-- Logs begin at Sat 2024-06-22 08:37:59 EEST, end at Thu 2024-07-04 19:54:20 EEST. -- Jul 04 19:53:28 volumio ntpd[846]: receive: Unexpected origin timestamp 0xea20e206.a7b876fe does not match aorg 0000000000.00000000 from server@156.17.20.254 xmt 0xea315208.1fc45e3b Jul 04 19:53:28 volumio ntpd[846]: receive: Unexpected origin timestamp 0xea20e206.a7a6d230 does not match aorg 0000000000.00000000 from server@80.50.102.206 xmt 0xea315208.1f30640f Jul 04 19:53:28 volumio systemd[1]: Starting Daily apt download activities... Jul 04 19:53:28 volumio systemd[1]: Starting Daily man-db regeneration... Jul 04 19:53:29 volumio systemd[1]: man-db.service: Succeeded. Jul 04 19:53:29 volumio systemd[1]: Started Daily man-db regeneration. Jul 04 19:53:30 volumio systemd[1]: apt-daily.service: Succeeded. Jul 04 19:53:30 volumio systemd[1]: Started Daily apt download activities. Jul 04 19:53:30 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces system playlist update Jul 04 19:53:30 volumio volumio[1029]: info: Ignoring MPD Status Update Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces state update: player Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::getState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces system playlist update Jul 04 19:53:30 volumio volumio[1029]: info: Ignoring MPD Status Update Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces state update: player Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::getState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces system playlist update Jul 04 19:53:30 volumio volumio[1029]: info: Ignoring MPD Status Update Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces state update: player Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::getState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces system playlist update Jul 04 19:53:30 volumio volumio[1029]: info: Ignoring MPD Status Update Jul 04 19:53:30 volumio volumio[1029]: info: Jul 04 19:53:30 volumio volumio[1029]: ---------------------------- MPD announces state update: player Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::getState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand status Jul 04 19:53:30 volumio go-librespot[1229]: time="2024-07-04T19:53:30+03:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 8ms Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand status took 7 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 7ms Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand status took 6 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 5ms Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand status took 4 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 4ms Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand status took 3 milliseconds Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 04 19:53:30 volumio go-librespot[1229]: time="2024-07-04T19:53:30+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2274" Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseState Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 04 19:53:30 volumio volumio[1029]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Jul 04 19:53:30 volumio volumio[1029]: verbose: ControllerMpd::parseTrackInfo Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:30 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Jul 04 19:53:30 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","position":0,"seek":25853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chris Standring - Ooh Bop","artist":"Smooth Jazz","album":null,"uri":"http://prmstrm.1.fm:8000/smoothjazz","trackType":""} Jul 04 19:53:30 volumio volumio[1029]: verbose: CURRENT POSITION 0 Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus play Jul 04 19:53:30 volumio volumio[1029]: info: Received an update from plugin. extracting info from payload Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:30 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Jul 04 19:53:30 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","position":0,"seek":25853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chris Standring - Ooh Bop","artist":"Smooth Jazz","album":null,"uri":"http://prmstrm.1.fm:8000/smoothjazz","trackType":""} Jul 04 19:53:30 volumio volumio[1029]: verbose: CURRENT POSITION 0 Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus play Jul 04 19:53:30 volumio volumio[1029]: info: Received an update from plugin. extracting info from payload Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:30 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Jul 04 19:53:30 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","position":0,"seek":25853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chris Standring - Ooh Bop","artist":"Smooth Jazz","album":null,"uri":"http://prmstrm.1.fm:8000/smoothjazz","trackType":""} Jul 04 19:53:30 volumio volumio[1029]: verbose: CURRENT POSITION 0 Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus play Jul 04 19:53:30 volumio volumio[1029]: info: Received an update from plugin. extracting info from payload Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: ControllerMpd::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:30 volumio volumio[1029]: info: CorePlayQueue::getTrack 0 Jul 04 19:53:30 volumio volumio[1029]: verbose: STATE SERVICE {"status":"play","position":0,"seek":25853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chris Standring - Ooh Bop","artist":"Smooth Jazz","album":null,"uri":"http://prmstrm.1.fm:8000/smoothjazz","trackType":""} Jul 04 19:53:30 volumio volumio[1029]: verbose: CURRENT POSITION 0 Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState stateService play Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::syncState currentStatus play Jul 04 19:53:30 volumio volumio[1029]: info: Received an update from plugin. extracting info from payload Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:30 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 69ms Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 67ms Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 66ms Jul 04 19:53:30 volumio volumio[1029]: info: ------------------------------ 64ms Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:30 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:31 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jul 04 19:53:31 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jul 04 19:53:32 volumio volumio[1029]: info: Discovery: A device disappeared from network Jul 04 19:53:32 volumio volumio[1029]: info: Discovery: Device volumio disappeared from network Jul 04 19:53:32 volumio volumio[1029]: info: Discovery: adding bc186acc-c8ef-4795-8630-c410cb1a48f2 Jul 04 19:53:32 volumio volumio[1029]: info: Discovery: Found device Volumio Jul 04 19:53:32 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="handling transfer player command from 372685973c59c9a3f843e6522802155518754cb1" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="loading track spotify:track:7yNf9YjeO5JXUE3JEBgnYc (paused: false, position: 4754ms)" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=trace msg="emitting websocket event: will_play" Jul 04 19:53:36 volumio volumio[1029]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","play_origin":""}} Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2270" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:7yNf9YjeO5JXUE3JEBgnYc" Jul 04 19:53:36 volumio go-librespot[1229]: time="2024-07-04T19:53:36+03:00" level=debug msg="requested aes key for file f5c71b61a1399e7480d84d6d2e3f5eb8cca4012e, gid: 7yNf9YjeO5JXUE3JEBgnYc" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="fetched first chunk of 8, total size is 3839980 bytes" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=trace msg="seek to 4754ms (diff: 66ms, samples: 209651, bytes: 134385)" Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=info msg="loaded track \"Babydoll\" (uri: spotify:track:7yNf9YjeO5JXUE3JEBgnYc, paused: false, position: 4754ms, duration: 97960ms)" Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 04 19:53:37 volumio volumio[1029]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="fetched chunk 2/7, size: 524288" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=trace msg="emitting websocket event: metadata" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=trace msg="emitting websocket event: active" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="sending successful reply for delaer request" Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","name":"Babydoll","artist_names":["Dominic Fike"],"album_name":"Don't Forget About Me, Demos","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","position":4754,"duration":97960,"release_date":"year:2018 month:10 day:16","track_number":3,"disc_number":1}} Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: received: {"type":"active","data":null} Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 04 19:53:37 volumio volumio[1029]: info: Aligning Spotify Volume to Volumio Volume Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:37 volumio volumio[1029]: info: Setting Spotify Volume from Volumio: 64 Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=trace msg="emitting websocket event: playing" Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="fetched chunk 3/7, size: 524288" Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","play_origin":""}} Jul 04 19:53:37 volumio volumio[1029]: info: Spotify is playing in volatile mode Jul 04 19:53:37 volumio volumio[1029]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: UNSET VOLATILE Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: {"status":"play","position":0,"title":"Chris Standring - Ooh Bop","artist":"Smooth Jazz","album":null,"albumart":"/albumart?cacheid=279&web=Smooth%20Jazz//extralarge","uri":"http://prmstrm.1.fm:8000/smoothjazz","trackType":"webradio","seek":1077278825,"duration":0,"samplerate":"","bitdepth":"","channels":2,"bitrate":"192 Kbps","random":null,"repeat":false,"repeatSingle":false,"consume":true,"volume":"64","dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":true,"updatedb":false,"volatile":false,"service":"webradio"} Jul 04 19:53:37 volumio volumio[1029]: info: Setting Spotify stop after unset volatile call Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: PUSH STATE SPOTIFY Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: {"status":"play","service":"spop","title":"Babydoll","artist":"Dominic Fike","album":"Don't Forget About Me, Demos","albumart":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","trackType":"spotify","seek":4754,"duration":97,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:37 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:37 volumio go-librespot[1229]: time="2024-07-04T19:53:37+03:00" level=debug msg="fetched chunk 1/7, size: 524288" Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: PUSH STATE SPOTIFY Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: {"status":"play","service":"spop","title":"Babydoll","artist":"Dominic Fike","album":"Don't Forget About Me, Demos","albumart":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","trackType":"spotify","seek":4754,"duration":97,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:53:37 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:53:37 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Jul 04 19:53:37 volumio volumio[1029]: info: Spotify Stop Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: SPOTIFY STOP Jul 04 19:53:37 volumio volumio[1029]: SPOTIFY: {"status":"play","title":"Babydoll","artist":"Dominic Fike","album":"Don't Forget About Me, Demos","albumart":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","trackType":"spotify","codec":"ogg","seek":4754,"duration":97,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":"64","dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jul 04 19:53:38 volumio volumio[1029]: SPOTIFY: SETTING SPOTIFY VOLUME 64 Jul 04 19:53:38 volumio volumio[1029]: info: Sending Spotify command with payload to local API: /player/volume Jul 04 19:53:38 volumio volumio[1029]: error: Failed to send command to Spotify local API: /player/volume: Error: Internal Server Error Jul 04 19:53:45 volumio kernel: hwmon hwmon1: Undervoltage detected! Jul 04 19:53:51 volumio sudo[1760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 19:53:51 volumio sudo[1760]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:53:51 volumio sudo[1760]: pam_unix(sudo:session): session closed for user root Jul 04 19:53:51 volumio sudo[1763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 19:53:51 volumio sudo[1763]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:53:51 volumio sudo[1763]: pam_unix(sudo:session): session closed for user root Jul 04 19:53:51 volumio kernel: hwmon hwmon1: Voltage normalised Jul 04 19:53:52 volumio volumio[1029]: verbose: New Socket.io Connection to 192.168.0.106 from 192.168.0.104 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 04 19:53:52 volumio volumio[1029]: info: Received Get System Info Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 19:53:52 volumio volumio[1029]: info: Discovery: Getting this device information Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:52 volumio volumio[1029]: info: Listing playlists Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 04 19:53:52 volumio volumio[1029]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 04 19:53:53 volumio volumio[1029]: info: Received Get System Info Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 19:53:53 volumio volumio[1029]: info: Discovery: Getting this device information Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:53 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 19:53:53 volumio go-librespot[1229]: time="2024-07-04T19:53:53+03:00" level=debug msg="fetched chunk 4/7, size: 524288" Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 04 19:53:54 volumio volumio[1029]: info: Received Get System Info Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 19:53:54 volumio volumio[1029]: info: Discovery: Getting this device information Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:53:54 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 19:54:00 volumio volumio[1029]: info: Getting Alsa Cards List without I2S DAC Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 04 19:54:00 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 19:54:02 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jul 04 19:54:08 volumio volumio[1029]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Jul 04 19:54:08 volumio sudo[1811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 19:54:08 volumio sudo[1811]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:08 volumio sudo[1811]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:08 volumio volumio[1029]: info: MPD Permissions set Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio sudo[1814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio sudo[1814]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio systemd[1]: Stopping Music Player Daemon... Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:08 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:08 volumio systemd[1]: mpd.service: Succeeded. Jul 04 19:54:08 volumio systemd[1]: Stopped Music Player Daemon. Jul 04 19:54:08 volumio volumio[1029]: error: Upnp client error: Error: This socket has been ended by the other party Jul 04 19:54:08 volumio systemd[1]: Starting Music Player Daemon... Jul 04 19:54:08 volumio sudo[1820]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 19:54:08 volumio sudo[1820]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:08 volumio sudo[1820]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:09 volumio mpd[1823]: Jul 04 19:54 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 19:54:09 volumio systemd[1]: Started Music Player Daemon. Jul 04 19:54:09 volumio sudo[1814]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:09 volumio volumio[1029]: error: updateQueue error: null Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 04 19:54:09 volumio volumio[1029]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 04 19:54:09 volumio volumio[1029]: info: Received Get System Version Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 19:54:09 volumio volumio[1029]: info: Received Get System Info Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 19:54:09 volumio volumio[1029]: info: Discovery: Getting this device information Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:54:09 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 19:54:14 volumio go-librespot[1229]: time="2024-07-04T19:54:14+03:00" level=debug msg="fetched chunk 5/7, size: 524288" Jul 04 19:54:18 volumio volumio[1029]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jul 04 19:54:18 volumio volumio[1029]: info: Preparing to save Alsa Options, stopping services first Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::volumioGetState Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::volumioPause Jul 04 19:54:18 volumio volumio[1029]: info: CoreStateMachine::pause Jul 04 19:54:18 volumio volumio[1029]: info: CoreStateMachine::stPlaybackTimer Jul 04 19:54:18 volumio volumio[1029]: info: CoreStateMachine::servicePause Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::servicePause Jul 04 19:54:18 volumio volumio[1029]: info: Spotify Received pause Jul 04 19:54:18 volumio volumio[1029]: SPOTIFY: SPOTIFY PAUSE Jul 04 19:54:18 volumio volumio[1029]: SPOTIFY: {"status":"play","title":"Babydoll","artist":"Dominic Fike","album":"Don't Forget About Me, Demos","albumart":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","trackType":"spotify","codec":"ogg","seek":4754,"duration":97,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":"64","dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jul 04 19:54:18 volumio volumio[1029]: info: Sending Spotify command to local API: /player/pause Jul 04 19:54:18 volumio volumio[1029]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":true,"i2sid":{"value":"generic-dac","label":"Generic I2S DAC"}} Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:18 volumio volumio[1029]: info: Enabling I2S DAC: Generic I2S DAC Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:18 volumio sudo[1885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Jul 04 19:54:18 volumio sudo[1885]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:18 volumio sudo[1885]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:18 volumio volumio[1029]: info: No Overlays Loaded Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:18 volumio sudo[1888]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dac Jul 04 19:54:18 volumio sudo[1888]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/#sound-dai-cells Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/compatible Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/status Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Jul 04 19:54:18 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Jul 04 19:54:18 volumio sudo[1888]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:18 volumio volumio[1029]: info: Setting default mixerSoftMaster for Softvolume device Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 04 19:54:18 volumio volumio[1029]: info: Updating Volume Controller Parameters: Device: 1 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; linear Vol Steps: 1 Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 04 19:54:18 volumio volumio[1029]: info: Disabling external Volume Control Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 19:54:18 volumio volumio[1029]: info: Enable softmixer device for audio device undefined Jul 04 19:54:18 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Jul 04 19:54:19 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:54:19 volumio volumio[1029]: info: I2S Param [object Object] successfully enabled Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: SPOTIFY VOLUME 64 Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: VOLUMIO VOLUME 100 Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: DELTA VOLUME ENOUGH: true Jul 04 19:54:19 volumio volumio[1029]: info: Setting Spotify Volume from Volumio: 100 Jul 04 19:54:19 volumio volumio[1029]: info: Software Volume ALSA configuration written Jul 04 19:54:19 volumio volumio[1029]: info: Preparing to generate the ALSA configuration file Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 19:54:19 volumio volumio[1029]: info: Getting Alsa Cards List without I2S DAC Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio go-librespot[1229]: time="2024-07-04T19:54:19+03:00" level=debug msg="pause track at 32283ms" Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 19:54:19 volumio volumio[1029]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jul 04 19:54:19 volumio volumio[1029]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 04 19:54:19 volumio volumio[1029]: info: Reading ALSA contributions from plugins. Jul 04 19:54:19 volumio go-librespot[1229]: time="2024-07-04T19:54:19+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 19:54:19 volumio volumio[1029]: info: Asound.conf file written Jul 04 19:54:19 volumio sudo[1922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jul 04 19:54:19 volumio sudo[1922]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio sudo[1922]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio go-librespot[1229]: time="2024-07-04T19:54:19+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 19:54:19 volumio go-librespot[1229]: time="2024-07-04T19:54:19+03:00" level=trace msg="emitting websocket event: paused" Jul 04 19:54:19 volumio volumio[1029]: info: Output device has changed, restarting MPD Jul 04 19:54:19 volumio sudo[1927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 19:54:19 volumio sudo[1927]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio volumio[1029]: info: Output device has changed, restarting Shairport Sync Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio sudo[1927]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio sudo[1930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 19:54:19 volumio sudo[1930]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio systemd[1]: Stopping Music Player Daemon... Jul 04 19:54:19 volumio volumio[1029]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 19:54:19 volumio volumio[1029]: info: Output device has changed, restarting MPD Jul 04 19:54:19 volumio systemd[1]: mpd.service: Succeeded. Jul 04 19:54:19 volumio systemd[1]: Stopped Music Player Daemon. Jul 04 19:54:19 volumio sudo[1937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 19:54:19 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio volumio[1029]: info: Output device has changed, restarting Shairport Sync Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio systemd[1]: Starting Music Player Daemon... Jul 04 19:54:19 volumio sudo[1940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 19:54:19 volumio sudo[1940]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jul 04 19:54:19 volumio systemd[1]: mpd.service: Succeeded. Jul 04 19:54:19 volumio systemd[1]: Stopped Music Player Daemon. Jul 04 19:54:19 volumio systemd[1]: Starting Music Player Daemon... Jul 04 19:54:19 volumio volumio[1029]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","play_origin":""}} Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: PUSH STATE SPOTIFY Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: {"status":"pause","service":"spop","title":"Babydoll","artist":"Dominic Fike","album":"Don't Forget About Me, Demos","albumart":"https://i.scdn.co/image/ab67616d00001e027b1b6f41c1645af9757d5616","uri":"spotify:track:7yNf9YjeO5JXUE3JEBgnYc","trackType":"spotify","seek":46754,"duration":97,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::servicePushState Jul 04 19:54:19 volumio volumio[1029]: info: CoreStateMachine::pushState Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::volumioPushState Jul 04 19:54:19 volumio volumio[1029]: info: MPD Permissions set Jul 04 19:54:19 volumio volumio[1029]: info: MPD Permissions set Jul 04 19:54:19 volumio volumio[1029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio sudo[1945]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 19:54:19 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 19:54:19 volumio volumio[1029]: info: Starting Shairport Sync Jul 04 19:54:19 volumio volumio[1029]: info: Starting Shairport Sync Jul 04 19:54:19 volumio sudo[1957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 19:54:19 volumio sudo[1957]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 04 19:54:19 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 04 19:54:19 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 04 19:54:19 volumio sudo[1960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 19:54:19 volumio sudo[1960]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 19:54:19 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 04 19:54:19 volumio sudo[1957]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio volumio[1029]: info: Shairport-Sync Started Jul 04 19:54:19 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 04 19:54:19 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jul 04 19:54:19 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 04 19:54:19 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 04 19:54:19 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 04 19:54:19 volumio sudo[1960]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:19 volumio volumio[1029]: info: Shairport-Sync Started Jul 04 19:54:20 volumio volumio[1029]: info: camilladsp spawned new process with pid 1966, instance 1, run: true Jul 04 19:54:20 volumio volumio[1029]: error: Upnp client error: Error: This socket has been ended by the other party Jul 04 19:54:20 volumio mpd[1952]: Jul 04 19:54 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 19:54:20 volumio systemd[1]: Started Music Player Daemon. Jul 04 19:54:20 volumio sudo[1940]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:20 volumio sudo[1930]: pam_unix(sudo:session): session closed for user root Jul 04 19:54:20 volumio volumio[1029]: error: MPD error: The expression evaluated to a falsy value: Jul 04 19:54:20 volumio volumio[1029]: assert.ok(self.idling) Jul 04 19:54:20 volumio volumio[1029]: error: The expression evaluated to a falsy value: Jul 04 19:54:20 volumio volumio[1029]: assert.ok(self.idling) Jul 04 19:54:20 volumio volumio[1029]: error: updateQueue error: null Jul 04 19:54:20 volumio volumio[1029]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Jul 04 19:54:20 volumio volumio[1029]: info: PLUGIN onReboot : networkfs Jul 04 19:54:20 volumio volumio[1029]: info: PLUGIN onReboot : audiophonicsonoff Jul 04 19:54:20 volumio volumio[1029]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 19:54:20 volumio volumio[1029]: TypeError: Cannot read property 'writeSync' of undefined Jul 04 19:54:20 volumio volumio[1029]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Jul 04 19:54:20 volumio volumio[1029]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Jul 04 19:54:20 volumio volumio[1029]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Jul 04 19:54:20 volumio volumio[1029]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jul 04 19:54:20 volumio volumio[1029]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jul 04 19:54:20 volumio volumio[1029]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Jul 04 19:54:20 volumio volumio[1029]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22) Jul 04 19:54:20 volumio volumio[1029]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:857:33) Jul 04 19:54:20 volumio volumio[1029]: at Socket.emit (events.js:315:20) Jul 04 19:54:20 volumio volumio[1029]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 04 19:54:20 volumio volumio[1029]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 04 19:54:20 volumio volumio[1029]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 19:54:20 volumio sudo[1984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-04 19:53 Jul 04 19:54:20 volumio sudo[1984]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"