-- Logs begin at Thu 2019-02-14 07:11:59 -03, end at Thu 2024-10-10 20:56:35 -03. -- Oct 10 20:55:00 volumio-max volumio[992]: info: VolumeController::SetAlsaVolume70 Oct 10 20:55:00 volumio-max volumio[992]: info: CoreCommandRouter::volumioGetState Oct 10 20:55:00 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:00 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:00 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:00 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:00 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:00 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:00 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:00 volumio-max volumio[992]: SPOTIFY: SPOTIFY VOLUME 75 Oct 10 20:55:00 volumio-max volumio[992]: SPOTIFY: VOLUMIO VOLUME 70 Oct 10 20:55:00 volumio-max volumio[992]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 10 20:55:00 volumio-max volumio[992]: info: Setting Spotify Volume from Volumio: 70 Oct 10 20:55:00 volumio-max sudo[17776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:00 volumio-max sudo[17776]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:00 volumio-max sudo[17776]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:00 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:01 volumio-max volumio[992]: SPOTIFY: SETTING SPOTIFY VOLUME 70 Oct 10 20:55:01 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/volume Oct 10 20:55:01 volumio-max go-librespot[1312]: time="2024-10-10T20:55:01-03:00" level=debug msg="update volume to 45874/65535" Oct 10 20:55:01 volumio-max go-librespot[1312]: time="2024-10-10T20:55:01-03:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 10 20:55:01 volumio-max go-librespot[1312]: time="2024-10-10T20:55:01-03:00" level=trace msg="emitting websocket event: volume" Oct 10 20:55:01 volumio-max volumio[992]: SPOTIFY: received: {"type":"volume","data":{"value":70,"max":100}} Oct 10 20:55:01 volumio-max volumio[992]: SPOTIFY: RECEIVED SPOTIFY VOLUME 70 Oct 10 20:55:02 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , handleBrowseUri Oct 10 20:55:02 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:08 volumio-max volumio[992]: Searching plugin music_service/podcast Oct 10 20:55:08 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , search Oct 10 20:55:08 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin podcast Oct 10 20:55:08 volumio-max volumio[992]: info: All search sources collected, pushing search results Oct 10 20:55:10 volumio-max volumio[992]: Searching plugin music_service/podcast Oct 10 20:55:10 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , search Oct 10 20:55:10 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin podcast Oct 10 20:55:10 volumio-max volumio[992]: info: All search sources collected, pushing search results Oct 10 20:55:13 volumio-max volumio[992]: Searching plugin music_service/podcast Oct 10 20:55:13 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , search Oct 10 20:55:13 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin podcast Oct 10 20:55:13 volumio-max volumio[992]: info: All search sources collected, pushing search results Oct 10 20:55:14 volumio-max volumio[992]: Searching plugin music_service/podcast Oct 10 20:55:14 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , search Oct 10 20:55:14 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin podcast Oct 10 20:55:14 volumio-max volumio[992]: info: All search sources collected, pushing search results Oct 10 20:55:17 volumio-max volumio[992]: Searching plugin music_service/podcast Oct 10 20:55:17 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: podcast , search Oct 10 20:55:17 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin podcast Oct 10 20:55:17 volumio-max volumio[992]: info: All search sources collected, pushing search results Oct 10 20:55:21 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 10 20:55:21 volumio-max volumio[992]: info: In handleBrowseUri, curUri=spotify Oct 10 20:55:22 volumio-max volumio[992]: info: New access token = BQDc21UEnLW2S_LFzBbzkIoX3wnY-Tr79hOfeCWrCYN5D29nJ-HOBITc4u4a9zmavjCy6ZRVvzY5AS6gEQqH8sreva6Y2drEik42swcUFgkgDQBvRhZEIuWzmugM1xmAgcec9qq8tgAoyDzN-i2I1jmrbr-NnZ9ig6AQbBiLqVI_WATjDFnNJRQ4AQntWDjXd0vvU5x6fnrvMTR-eJuVfTOKq-DrTqlnF0YoWgSVnL8nyduxXxu84NIm-4Cr Oct 10 20:55:22 volumio-max volumiologrotate[662]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 10 20:55:22 volumio-max volumiologrotate[662]: ls: cannot access 'MAX': No such file or directory Oct 10 20:55:22 volumio-max volumio[992]: info: New access token = BQDQTGV3fuUqVODsQMVAU9LZ7pKNGVW_YvSeTqzSLXZJga3YS2-DNaW6GteeS98HuAMDkoUToqwU5Ah7uNuJ8cCru0DZMW1kybAcaqCm_JmzU32RImo7QSpJzdACK5AZF3Kf0NJHIBYEyPC-uDX_5TS3TrtkaIHHVLaCZ3XttgVDxZ46DDG5FXIajXhntqnynl-rnefMprdwWUo_y59PyA3W3CFu7r6_YS2W9we8Jr_FPZ1sII7JuEfLTy3F Oct 10 20:55:22 volumio-max volumio[992]: info: New access token = BQAKb2re9jvSoYBaMkUyr8hZVwyMHqJY5pz64BYKv-v71D08Gef8iW15b0dYtCpy0a7AiNhwbjai9TYJlRcyQTpdtrFD3zjrXXAIy8LWTGFyn7u3adN-GnBQPdPrFIsOoqRuyeKdCn3GPSrcl1KRW0XAQPQYXMuMevX0lzG8yiJIEBGIVaEaUuI_2zJ50G79oLNkxwX9JrLIjQGayGAhQepyikYRRs-q6e4cF0hyICqtPGyjMynL2e1nhPr2 Oct 10 20:55:22 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:22 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:22 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:22 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:31 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 10 20:55:31 volumio-max volumio[992]: info: In handleBrowseUri, curUri=spotify/myalbums Oct 10 20:55:34 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:36 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::ClearQueue Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::stPlaybackTimer Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::serviceStop Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::serviceStop Oct 10 20:55:36 volumio-max volumio[992]: info: [1728604536485] ControllerCalmRadio::stop Oct 10 20:55:36 volumio-max volumio[992]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::clearPlayQueue Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::addQueueItems Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::addQueueItems Oct 10 20:55:36 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:36 volumio-max volumio[992]: info: Adding Item to queue: spotify:album:2WFkJi4USarY1qe3yjifjG Oct 10 20:55:36 volumio-max volumio[992]: info: Exploding uri spotify:album:2WFkJi4USarY1qe3yjifjG in service spop Oct 10 20:55:36 volumio-max volumio[992]: SPOTIFY: EXPLODING URI:spotify:album:2WFkJi4USarY1qe3yjifjG Oct 10 20:55:36 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:36 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:36 volumio-max sudo[17828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:36 volumio-max sudo[17828]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:36 volumio-max volumio[992]: info: Oct 10 20:55:36 volumio-max volumio[992]: ---------------------------- MPD announces state update: player Oct 10 20:55:36 volumio-max volumio[992]: info: sendMpdCommand stop took 75 milliseconds Oct 10 20:55:36 volumio-max volumio[992]: info: ControllerMpd::getState Oct 10 20:55:36 volumio-max volumio[992]: verbose: ControllerMpd::sendMpdCommand status Oct 10 20:55:36 volumio-max volumio[992]: info: sendMpdCommand status took 5 milliseconds Oct 10 20:55:36 volumio-max volumio[992]: verbose: ControllerMpd::parseState Oct 10 20:55:36 volumio-max volumio[992]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 20:55:36 volumio-max systemd[1]: Stopping peppymeterbasic Daemon... Oct 10 20:55:36 volumio-max systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Oct 10 20:55:36 volumio-max volumio[992]: info: sendMpdCommand playlistinfo took 52 milliseconds Oct 10 20:55:36 volumio-max volumio[992]: verbose: ControllerMpd::parseTrackInfo Oct 10 20:55:36 volumio-max volumio[992]: info: ControllerMpd::pushState Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: 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":"Rebecca Reads - - - The Stargazer","artist":"MY BEST SLEEP EVER - ROYALTY FREE - sampler","album":null,"uri":"https://streams.calmradio.com/api/4582/128/stream","trackType":""} Oct 10 20:55:36 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService stop Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:36 volumio-max volumio[992]: info: No code Oct 10 20:55:36 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:36 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:36 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:36 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:36 volumio-max systemd[1]: peppymeterbasic.service: Succeeded. Oct 10 20:55:36 volumio-max systemd[1]: Stopped peppymeterbasic Daemon. Oct 10 20:55:36 volumio-max sudo[17828]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:36 volumio-max volumio[992]: info: ------------------------------ 131ms Oct 10 20:55:36 volumio-max volumio[992]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 20:55:36 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:36 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:36 volumio-max sudo[17835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:36 volumio-max sudo[17835]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:36 volumio-max sudo[17835]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:36 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:36 volumio-max sudo[17838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:36 volumio-max sudo[17838]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:36 volumio-max sudo[17838]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:37 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:37 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:37 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:37 volumio-max sudo[17841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:37 volumio-max sudo[17841]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:37 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:37 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 60 seconds. Oct 10 20:55:37 volumio-max sudo[17841]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:37 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:37 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:37 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:37 volumio-max volumio[992]: info: camilladsp spawned new process with pid 17843, instance 1, run: true Oct 10 20:55:37 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:37 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:37 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:37 volumio-max volumio[992]: info: CoreCommandRouter::volumioPlay Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::play index 0 Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::play index undefined Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:37 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:37 volumio-max volumio[992]: info: CoreStateMachine::startPlaybackTimer Oct 10 20:55:37 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:37 volumio-max volumio[992]: info: [1728604537431] ControllerSpotify::clearAddPlayTrack Oct 10 20:55:37 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/play Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=debug msg="resolved context of track" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=trace msg="emitting websocket event: will_play" Oct 10 20:55:37 volumio-max volumio[992]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","play_origin":"go-librespot"}} Oct 10 20:55:37 volumio-max go-librespot[1312]: time="2024-10-10T20:55:37-03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="selected format OGG_VORBIS_320 (37e4c842c03de144802600f95144e9850d976716)" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="requested aes key for file 37e4c842c03de144802600f95144e9850d976716, gid: 6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1695" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1311" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=debug msg="fetched first chunk of 31, total size is 15815712 bytes" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:38 volumio-max go-librespot[1312]: time="2024-10-10T20:55:38-03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:39 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:55:39 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:55:39 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="created new output device" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=info msg="loaded track \"No Son of Mine - 2007 Remaster\" (paused: false, position: 0ms, duration: 399106ms, prefetched: false)" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:39 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="fetched chunk 1/30, size: 524288" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="fetched chunk 3/30, size: 524288" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=trace msg="scheduling prefetch in 368s" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=trace msg="emitting websocket event: metadata" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="fetched chunk 2/30, size: 524288" uri="spotify:track:6YsCavQbx3YITYsnIKvF3j" Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","name":"No Son of Mine - 2007 Remaster","artist_names":["Genesis"],"album_name":"We Can't Dance (2007 Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","position":0,"duration":399106,"release_date":"year:1991 month:11 day:11","track_number":1,"disc_number":1}} Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:39 volumio-max go-librespot[1312]: time="2024-10-10T20:55:39-03:00" level=trace msg="emitting websocket event: playing" Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","play_origin":"go-librespot"}} Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":0,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:39 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:39 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:39 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":0,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:39 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:39 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":0,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:39 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:39 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:39 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":0,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:39 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus play Oct 10 20:55:39 volumio-max volumio[992]: info: Received an update from plugin. extracting info from payload Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:39 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:39 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:39 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:39 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:39 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:39 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:39 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:39 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:39 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:39 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:39 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:39 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:39 volumio-max sudo[17856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:39 volumio-max sudo[17856]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:40 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:40 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:40 volumio-max systemd[1]: Started peppymeterbasic Daemon. Oct 10 20:55:40 volumio-max sudo[17860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:40 volumio-max sudo[17860]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:40 volumio-max sudo[17856]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:40 volumio-max sudo[17860]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:40 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 10 20:55:40 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:40 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:41 volumio-max volumio[17859]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:55:41 volumio-max volumio[17859]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:55:49 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::ClearQueue Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::stPlaybackTimer Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:49 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:49 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::serviceStop Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::serviceStop Oct 10 20:55:49 volumio-max volumio[992]: info: Spotify Stop Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: SPOTIFY STOP Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: {"status":"play","position":0,"title":"No Son Of Mine - Remastered 2007","artist":"Genesis","album":"We Can't Dance","albumart":"https://i.scdn.co/image/ab67616d0000b27301f20b98b794099707e43375","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","codec":"ogg","seek":0,"duration":399,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":70,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 10 20:55:49 volumio-max volumio[992]: info: Sending Spotify command to local API: /player/pause Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::clearPlayQueue Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::addQueueItems Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::addQueueItems Oct 10 20:55:49 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:49 volumio-max volumio[992]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWZjqjZMudx9T Oct 10 20:55:49 volumio-max volumio[992]: info: Exploding uri spotify:playlist:37i9dQZF1DWZjqjZMudx9T in service spop Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWZjqjZMudx9T Oct 10 20:55:49 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:49 volumio-max sudo[17872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:49 volumio-max sudo[17872]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:49 volumio-max systemd[1]: Stopping peppymeterbasic Daemon... Oct 10 20:55:49 volumio-max systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Oct 10 20:55:49 volumio-max volumio[992]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 20:55:49 volumio-max go-librespot[1312]: time="2024-10-10T20:55:49-03:00" level=debug msg="pause track at 11265ms" Oct 10 20:55:49 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 60 seconds. Oct 10 20:55:49 volumio-max systemd[1]: peppymeterbasic.service: Succeeded. Oct 10 20:55:49 volumio-max systemd[1]: Stopped peppymeterbasic Daemon. Oct 10 20:55:49 volumio-max sudo[17872]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:49 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:49 volumio-max go-librespot[1312]: time="2024-10-10T20:55:49-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:49 volumio-max go-librespot[1312]: time="2024-10-10T20:55:49-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:49 volumio-max go-librespot[1312]: time="2024-10-10T20:55:49-03:00" level=trace msg="emitting websocket event: paused" Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","play_origin":"go-librespot"}} Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: {"status":"pause","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":10000,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:49 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"No Son of Mine - 2007 Remaster","artist":"Genesis","album":"We Can't Dance (2007 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02715989800acd29a992275c31","uri":"spotify:track:6YsCavQbx3YITYsnIKvF3j","trackType":"spotify","seek":10000,"duration":399,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:49 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService pause Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:49 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:49 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:49 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:49 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:49 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:49 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:49 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:49 volumio-max sudo[17877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:49 volumio-max sudo[17877]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:50 volumio-max sudo[17877]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:50 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:50 volumio-max volumio[992]: info: camilladsp spawned new process with pid 17879, instance 1, run: true Oct 10 20:55:50 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:50 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:50 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:50 volumio-max volumio[992]: info: CoreCommandRouter::volumioPlay Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::play index 0 Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::play index undefined Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:50 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:50 volumio-max volumio[992]: info: CoreStateMachine::startPlaybackTimer Oct 10 20:55:50 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:50 volumio-max volumio[992]: info: [1728604550319] ControllerSpotify::clearAddPlayTrack Oct 10 20:55:50 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/play Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=debug msg="resolved context of track" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=trace msg="emitting websocket event: will_play" Oct 10 20:55:50 volumio-max volumio[992]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","play_origin":"go-librespot"}} Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=debug msg="selected format OGG_VORBIS_320 (93276a652b174e624b7314de911b2f54db092a1c)" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:50 volumio-max go-librespot[1312]: time="2024-10-10T20:55:50-03:00" level=debug msg="requested aes key for file 93276a652b174e624b7314de911b2f54db092a1c, gid: 4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="fetched first chunk of 18, total size is 9278940 bytes" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=info msg="loaded track \"El Efecto\" (paused: false, position: 0ms, duration: 217142ms, prefetched: false)" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:55:51 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:4SJHHpKhcuXwDsCsPqshXj" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=trace msg="scheduling prefetch in 187s" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=trace msg="emitting websocket event: metadata" Oct 10 20:55:51 volumio-max volumio[992]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","name":"El Efecto","artist_names":["Rauw Alejandro","Chencho Corleone"],"album_name":"El Efecto","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","position":0,"duration":217142,"release_date":"year:2019 month:3 day:15","track_number":1,"disc_number":1}} Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:51 volumio-max go-librespot[1312]: time="2024-10-10T20:55:51-03:00" level=trace msg="emitting websocket event: playing" Oct 10 20:55:51 volumio-max volumio[992]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","play_origin":"go-librespot"}} Oct 10 20:55:51 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:51 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:51 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:51 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:51 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:51 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:51 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:51 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:52 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:52 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:52 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:52 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:52 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:52 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:52 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:52 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus play Oct 10 20:55:52 volumio-max volumio[992]: info: Received an update from plugin. extracting info from payload Oct 10 20:55:52 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:52 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:52 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:52 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:52 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:52 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:52 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:52 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:52 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:52 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:52 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:52 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:52 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:52 volumio-max sudo[17893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:52 volumio-max sudo[17893]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:52 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:52 volumio-max sudo[17896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:52 volumio-max sudo[17896]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:52 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:52 volumio-max systemd[1]: Started peppymeterbasic Daemon. Oct 10 20:55:52 volumio-max sudo[17893]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:52 volumio-max sudo[17896]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:52 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:52 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:52 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 10 20:55:53 volumio-max volumio[17897]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:55:53 volumio-max volumio[17897]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:55:56 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::ClearQueue Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::stPlaybackTimer Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:56 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:56 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::serviceStop Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::serviceStop Oct 10 20:55:56 volumio-max volumio[992]: info: Spotify Stop Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: SPOTIFY STOP Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: {"status":"play","position":0,"title":"El Efecto","artist":"Rauw Alejandro","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d0000b273976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","codec":"ogg","seek":0,"duration":217,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":70,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 10 20:55:56 volumio-max volumio[992]: info: Sending Spotify command to local API: /player/pause Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::clearPlayQueue Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::addQueueItems Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::addQueueItems Oct 10 20:55:56 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:55:56 volumio-max volumio[992]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DXe1ikyKZnRtc Oct 10 20:55:56 volumio-max volumio[992]: info: Exploding uri spotify:playlist:37i9dQZF1DXe1ikyKZnRtc in service spop Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DXe1ikyKZnRtc Oct 10 20:55:56 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:56 volumio-max sudo[17906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:56 volumio-max sudo[17906]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:56 volumio-max systemd[1]: Stopping peppymeterbasic Daemon... Oct 10 20:55:56 volumio-max systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Oct 10 20:55:56 volumio-max go-librespot[1312]: time="2024-10-10T20:55:56-03:00" level=debug msg="pause track at 5594ms" Oct 10 20:55:56 volumio-max volumio[992]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 20:55:56 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 60 seconds. Oct 10 20:55:56 volumio-max systemd[1]: peppymeterbasic.service: Succeeded. Oct 10 20:55:56 volumio-max systemd[1]: Stopped peppymeterbasic Daemon. Oct 10 20:55:56 volumio-max sudo[17906]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:56 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:56 volumio-max go-librespot[1312]: time="2024-10-10T20:55:56-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:56 volumio-max go-librespot[1312]: time="2024-10-10T20:55:56-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:56 volumio-max go-librespot[1312]: time="2024-10-10T20:55:56-03:00" level=trace msg="emitting websocket event: paused" Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","play_origin":"go-librespot"}} Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: {"status":"pause","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":4000,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:56 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"El Efecto","artist":"Rauw Alejandro, Chencho Corleone","album":"El Efecto","albumart":"https://i.scdn.co/image/ab67616d00001e02976be14b5e8f1e7b5d8e340c","uri":"spotify:track:4SJHHpKhcuXwDsCsPqshXj","trackType":"spotify","seek":4000,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:56 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService pause Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:56 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:56 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:56 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:56 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:56 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:56 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:55:56 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:56 volumio-max sudo[17912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:55:56 volumio-max sudo[17912]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:56 volumio-max sudo[17912]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:56 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:55:57 volumio-max volumio[992]: info: camilladsp spawned new process with pid 17914, instance 1, run: true Oct 10 20:55:57 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:55:57 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:55:57 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:55:57 volumio-max volumio[992]: info: CoreCommandRouter::volumioPlay Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::play index 0 Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::play index undefined Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:55:57 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:57 volumio-max volumio[992]: info: CoreStateMachine::startPlaybackTimer Oct 10 20:55:57 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:57 volumio-max volumio[992]: info: [1728604557187] ControllerSpotify::clearAddPlayTrack Oct 10 20:55:57 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/play Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=debug msg="resolved context of track" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=trace msg="emitting websocket event: will_play" Oct 10 20:55:57 volumio-max volumio[992]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","play_origin":"go-librespot"}} Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=debug msg="selected format OGG_VORBIS_320 (6bf69c38f42f71e0ef90a5a27f292d74fc7c3453)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:57 volumio-max go-librespot[1312]: time="2024-10-10T20:55:57-03:00" level=debug msg="requested aes key for file 6bf69c38f42f71e0ef90a5a27f292d74fc7c3453, gid: 7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="fetched first chunk of 20, total size is 10093580 bytes" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=info msg="loaded track \"CALL ME MAYBE\" (paused: false, position: 0ms, duration: 222401ms, prefetched: false)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:55:58 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=trace msg="scheduling prefetch in 192s" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=trace msg="emitting websocket event: metadata" Oct 10 20:55:58 volumio-max volumio[992]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","name":"CALL ME MAYBE","artist_names":["Duki"],"album_name":"CALL ME MAYBE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","position":0,"duration":222401,"release_date":"year:2023 month:12 day:7","track_number":1,"disc_number":1}} Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:55:58 volumio-max go-librespot[1312]: time="2024-10-10T20:55:58-03:00" level=trace msg="emitting websocket event: playing" Oct 10 20:55:58 volumio-max volumio[992]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","play_origin":"go-librespot"}} Oct 10 20:55:58 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:58 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":0,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:58 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:58 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:58 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":0,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:58 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:58 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:58 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:55:59 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:55:59 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":0,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:59 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:55:59 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:59 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":0,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:55:59 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:55:59 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:55:59 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus play Oct 10 20:55:59 volumio-max volumio[992]: info: Received an update from plugin. extracting info from payload Oct 10 20:55:59 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:59 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:59 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:55:59 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:59 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:59 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:59 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:55:59 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:55:59 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:55:59 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:55:59 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:55:59 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:59 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:55:59 volumio-max sudo[17928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:59 volumio-max sudo[17928]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:59 volumio-max sudo[17931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:55:59 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:59 volumio-max sudo[17931]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:55:59 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:55:59 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 10 20:55:59 volumio-max sudo[17928]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:59 volumio-max systemd[1]: Started peppymeterbasic Daemon. Oct 10 20:55:59 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:55:59 volumio-max sudo[17931]: pam_unix(sudo:session): session closed for user root Oct 10 20:55:59 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:00 volumio-max volumio[17933]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:56:00 volumio-max volumio[17933]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::volumioSeek Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::seek Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: info: TRACKBLOCK {"service":"spop","type":"song","name":"CALL ME MAYBE","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","albumart":"https://i.scdn.co/image/ab67616d0000b2737e73b2aae4ae0085a1f7d825","duration":222,"channels":2} Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::startPlaybackTimer Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: info: Spotify seek to: 39000 Oct 10 20:56:03 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/seek Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:03 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=debug msg="seek track to 39000ms" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=trace msg="seek to 39000ms (diff: 213ms, samples: 1719900, bytes: 1743418)" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:56:03 volumio-max sudo[17941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:56:03 volumio-max sudo[17941]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:03 volumio-max sudo[17941]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:03 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=trace msg="scheduling prefetch in 153s" Oct 10 20:56:03 volumio-max go-librespot[1312]: time="2024-10-10T20:56:03-03:00" level=trace msg="emitting websocket event: seek" Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","position":39000,"duration":222401,"play_origin":"go-librespot"}} Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":39000,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":39000,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:03 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus play Oct 10 20:56:03 volumio-max volumio[992]: info: Received an update from plugin. extracting info from payload Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:03 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:03 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:03 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:03 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:03 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:56:03 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:56:03 volumio-max sudo[17944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:56:03 volumio-max sudo[17944]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:03 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:03 volumio-max sudo[17947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:56:03 volumio-max sudo[17944]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:03 volumio-max sudo[17947]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:03 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:03 volumio-max sudo[17947]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:03 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:10 volumio-max go-librespot[1312]: time="2024-10-10T20:56:10-03:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:7sQkCW2vO8Tbx57oQwAIKk" Oct 10 20:56:18 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:56:18 volumio-max volumio[992]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::ClearQueue Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::stPlaybackTimer Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:18 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:56:18 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:18 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:18 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::serviceStop Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:18 volumio-max volumio[992]: info: CoreCommandRouter::serviceStop Oct 10 20:56:18 volumio-max volumio[992]: info: Spotify Stop Oct 10 20:56:18 volumio-max volumio[992]: SPOTIFY: SPOTIFY STOP Oct 10 20:56:18 volumio-max volumio[992]: SPOTIFY: {"status":"play","position":0,"title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d0000b2737e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","codec":"ogg","seek":39000,"duration":222,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":70,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 10 20:56:18 volumio-max volumio[992]: info: Sending Spotify command to local API: /player/pause Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::clearPlayQueue Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:56:18 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:56:18 volumio-max volumio[992]: info: CoreStateMachine::addQueueItems Oct 10 20:56:18 volumio-max volumio[992]: info: CorePlayQueue::addQueueItems Oct 10 20:56:18 volumio-max volumio[992]: info: Preload queue cleared Oct 10 20:56:18 volumio-max volumio[992]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWX2Ln16qIxDF Oct 10 20:56:18 volumio-max volumio[992]: info: Exploding uri spotify:playlist:37i9dQZF1DWX2Ln16qIxDF in service spop Oct 10 20:56:18 volumio-max volumio[992]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWX2Ln16qIxDF Oct 10 20:56:18 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:56:18 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:18 volumio-max go-librespot[1312]: time="2024-10-10T20:56:18-03:00" level=debug msg="pause track at 54244ms" Oct 10 20:56:18 volumio-max sudo[17951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:56:18 volumio-max sudo[17951]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:18 volumio-max systemd[1]: Stopping peppymeterbasic Daemon... Oct 10 20:56:18 volumio-max systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Oct 10 20:56:18 volumio-max volumio[992]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 20:56:18 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 60 seconds. Oct 10 20:56:18 volumio-max systemd[1]: peppymeterbasic.service: Succeeded. Oct 10 20:56:18 volumio-max systemd[1]: Stopped peppymeterbasic Daemon. Oct 10 20:56:18 volumio-max sudo[17951]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:18 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:56:18 volumio-max go-librespot[1312]: time="2024-10-10T20:56:18-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:19 volumio-max go-librespot[1312]: time="2024-10-10T20:56:19-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:19 volumio-max go-librespot[1312]: time="2024-10-10T20:56:19-03:00" level=trace msg="emitting websocket event: paused" Oct 10 20:56:19 volumio-max volumio[992]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","play_origin":"go-librespot"}} Oct 10 20:56:19 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:56:19 volumio-max volumio[992]: SPOTIFY: {"status":"pause","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":55000,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:19 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:56:19 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:19 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"CALL ME MAYBE","artist":"Duki","album":"CALL ME MAYBE","albumart":"https://i.scdn.co/image/ab67616d00001e027e73b2aae4ae0085a1f7d825","uri":"spotify:track:7sQkCW2vO8Tbx57oQwAIKk","trackType":"spotify","seek":55000,"duration":222,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:19 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:56:19 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService pause Oct 10 20:56:19 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:56:19 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:19 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:19 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:56:19 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:19 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:19 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:19 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 10 20:56:19 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:19 volumio-max sudo[17956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 10 20:56:19 volumio-max sudo[17956]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:19 volumio-max sudo[17956]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:19 volumio-max volumio[992]: info: peppymeterbasic Daemon Stop Oct 10 20:56:19 volumio-max volumio[992]: info: camilladsp spawned new process with pid 17958, instance 1, run: true Oct 10 20:56:20 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushQueue Oct 10 20:56:20 volumio-max volumio[992]: info: CorePlayQueue::saveQueue Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::updateTrackBlock Oct 10 20:56:20 volumio-max volumio[992]: info: CorePlayQueue::getTrackBlock Oct 10 20:56:20 volumio-max volumio[992]: info: CoreCommandRouter::volumioPlay Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::play index 0 Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::stop Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::play index undefined Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 20:56:20 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:20 volumio-max volumio[992]: info: CoreStateMachine::startPlaybackTimer Oct 10 20:56:20 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:20 volumio-max volumio[992]: info: [1728604580572] ControllerSpotify::clearAddPlayTrack Oct 10 20:56:20 volumio-max volumio[992]: info: Sending Spotify command with payload to local API: /player/play Oct 10 20:56:20 volumio-max go-librespot[1312]: time="2024-10-10T20:56:20-03:00" level=debug msg="resolved context of track" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:20 volumio-max go-librespot[1312]: time="2024-10-10T20:56:20-03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:20 volumio-max go-librespot[1312]: time="2024-10-10T20:56:20-03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=trace msg="emitting websocket event: will_play" Oct 10 20:56:21 volumio-max volumio[992]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","play_origin":"go-librespot"}} Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="selected format OGG_VORBIS_320 (af43bf065e1063b09aeba1689193d9a1a4fc8156)" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="requested aes key for file af43bf065e1063b09aeba1689193d9a1a4fc8156, gid: 32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="fetched first chunk of 14, total size is 6930573 bytes" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 10 20:56:21 volumio-max volumio[992]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 10 20:56:21 volumio-max volumio[992]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=info msg="loaded track \"FANÁTICO\" (paused: false, position: 0ms, duration: 162139ms, prefetched: false)" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max volumio[992]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=trace msg="scheduling prefetch in 131s" Oct 10 20:56:21 volumio-max go-librespot[1312]: time="2024-10-10T20:56:21-03:00" level=trace msg="emitting websocket event: metadata" Oct 10 20:56:21 volumio-max volumio[992]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","name":"FANÁTICO","artist_names":["Lali"],"album_name":"FANÁTICO","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fa5d0f60d3acd25af6b0637b","position":0,"duration":162139,"release_date":"year:2024 month:9 day:27","track_number":1,"disc_number":1}} Oct 10 20:56:22 volumio-max go-librespot[1312]: time="2024-10-10T20:56:22-03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 10 20:56:22 volumio-max go-librespot[1312]: time="2024-10-10T20:56:22-03:00" level=trace msg="emitting websocket event: playing" Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","play_origin":"go-librespot"}} Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"FANÁTICO","artist":"Lali","album":"FANÁTICO","albumart":"https://i.scdn.co/image/ab67616d00001e02fa5d0f60d3acd25af6b0637b","uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","trackType":"spotify","seek":0,"duration":162,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:22 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:56:22 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:22 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"FANÁTICO","artist":"Lali","album":"FANÁTICO","albumart":"https://i.scdn.co/image/ab67616d00001e02fa5d0f60d3acd25af6b0637b","uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","trackType":"spotify","seek":0,"duration":162,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:22 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus stop Oct 10 20:56:22 volumio-max volumiologrotate[662]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 10 20:56:22 volumio-max volumiologrotate[662]: ls: cannot access 'MAX': No such file or directory Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: PUSH STATE SPOTIFY Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: {"status":"play","service":"spop","title":"FANÁTICO","artist":"Lali","album":"FANÁTICO","albumart":"https://i.scdn.co/image/ab67616d00001e02fa5d0f60d3acd25af6b0637b","uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","trackType":"spotify","seek":0,"duration":162,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:22 volumio-max volumio[992]: info: CoreCommandRouter::servicePushState Oct 10 20:56:22 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:22 volumio-max volumio[992]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"FANÁTICO","artist":"Lali","album":"FANÁTICO","albumart":"https://i.scdn.co/image/ab67616d00001e02fa5d0f60d3acd25af6b0637b","uri":"spotify:track:32fRErxI6gKskZXSbEAAAn","trackType":"spotify","seek":0,"duration":162,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 10 20:56:22 volumio-max volumio[992]: verbose: CURRENT POSITION 0 Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::syncState stateService play Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::syncState currentStatus play Oct 10 20:56:22 volumio-max volumio[992]: info: Received an update from plugin. extracting info from payload Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:22 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:22 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 20:56:22 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:22 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:22 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:22 volumio-max volumio[992]: info: CoreStateMachine::pushState Oct 10 20:56:22 volumio-max volumio[992]: info: CorePlayQueue::getTrack 0 Oct 10 20:56:22 volumio-max volumio[992]: info: CoreCommandRouter::volumioPushState Oct 10 20:56:22 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output update for this device Oct 10 20:56:22 volumio-max volumio[992]: info: MRS: Pushing multiroomSync output Oct 10 20:56:22 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:56:22 volumio-max volumio[992]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 10 20:56:22 volumio-max sudo[18018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:56:22 volumio-max sudo[18018]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:22 volumio-max volumio[992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Oct 10 20:56:22 volumio-max sudo[18021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 10 20:56:22 volumio-max sudo[18021]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 20:56:22 volumio-max systemd[1]: Started peppymeterbasic Daemon. Oct 10 20:56:22 volumio-max sudo[18018]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:22 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:22 volumio-max sudo[18021]: pam_unix(sudo:session): session closed for user root Oct 10 20:56:22 volumio-max volumio[992]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 10 20:56:22 volumio-max volumio[992]: info: peppymeterbasic Daemon Started Oct 10 20:56:23 volumio-max volumio[18022]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:56:23 volumio-max volumio[18022]: libpng warning: iCCP: known incorrect sRGB profile Oct 10 20:56:32 volumio-max go-librespot[1312]: time="2024-10-10T20:56:32-03:00" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:32fRErxI6gKskZXSbEAAAn" Oct 10 20:56:35 volumio-max volumio[992]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Oct 10 20:56:35 volumio-max volumio[992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Oct 10 20:56:35 volumio-max volumio[992]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 20:56:35 volumio-max volumio[992]: TypeError: Cannot read property 'then' of undefined Oct 10 20:56:35 volumio-max volumio[992]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Oct 10 20:56:35 volumio-max volumio[992]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30) Oct 10 20:56:35 volumio-max volumio[992]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1442:26) Oct 10 20:56:35 volumio-max volumio[992]: at Socket.emit (events.js:315:20) Oct 10 20:56:35 volumio-max volumio[992]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 10 20:56:35 volumio-max volumio[992]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 10 20:56:35 volumio-max volumio[992]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 20:56:35 volumio-max sudo[18041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-10 20:55 Oct 10 20:56:35 volumio-max sudo[18041]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"