-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2025-04-18 11:07:20 CEST. -- Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:00 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:00 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:00 volumio volumio[13784]: debug: API:pushMultiroomDevices Apr 18 11:06:00 volumio volumio[13784]: info: MPD Permissions set Apr 18 11:06:00 volumio volumio[13784]: info: MPD Permissions set Apr 18 11:06:00 volumio volumio[13784]: info: Spotify config file written Apr 18 11:06:00 volumio volumio[13784]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio sudo[13966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 18 11:06:00 volumio sudo[13966]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio systemd[1]: Stopping go-librespot Daemon... Apr 18 11:06:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 18 11:06:00 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Apr 18 11:06:00 volumio systemd[1]: Stopped go-librespot Daemon. Apr 18 11:06:00 volumio sudo[13845]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:00 volumio volumio[13784]: info: No need to fix Spotify hosts Apr 18 11:06:00 volumio systemd[1]: Started go-librespot Daemon. Apr 18 11:06:00 volumio sudo[13966]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio go-librespot[13973]: Librespot-go daemon starting... Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=info msg="generated new device id: 3b7ae5c31e4cee08e7916c39c6b4efdb49997c81" Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="stored credentials found for lemur30" Apr 18 11:06:00 volumio volumio[13784]: info: Volumio called home Apr 18 11:06:00 volumio volumio[13784]: info: [jellyfin-poller] Polled http://192.168.2.158:8096: online Apr 18 11:06:00 volumio volumio[13784]: info: Starting Shairport Sync Apr 18 11:06:00 volumio volumio[13784]: info: Starting Shairport Sync Apr 18 11:06:00 volumio sudo[13991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 11:06:00 volumio volumio[13784]: info: Starting Shairport Sync Apr 18 11:06:00 volumio sudo[13991]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:00 volumio sudo[13995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 11:06:00 volumio sudo[13995]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 11:06:00 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 18 11:06:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 11:06:00 volumio sudo[14003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 11:06:00 volumio sudo[14003]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:00 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:00 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="zeroconf server listening on port 41929" Apr 18 11:06:00 volumio sudo[13991]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio sudo[13995]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio shairport-sync[14005]: free(): double free detected in tcache 2 Apr 18 11:06:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 11:06:00 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=6/ABRT Apr 18 11:06:00 volumio systemd[1]: shairport-sync.service: Failed with result 'signal'. Apr 18 11:06:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="obtained new client token: AAClFcZKMeJFSQg2uy0/fMHNvsq8WhEuBTIQUvUjWLnn9nxhMrVmFktzM4dj8eitoWic8n4knDVG/XeUfolOQQ4+vPUEWFAQxC+Lt3m4DPRzgyfFLJw7oardeOeHsy3Rr03pDFAmcuvx2VEonIhccqhvtUMv3JonFB579VkhNi8sKHuP1oJel98180MPBmEvHPwTuOrD6SZFa0+kry8zA6C/8mEC3/lgoBWenMvs9hgMHXQNzCm1Ws9oHwelmw==" Apr 18 11:06:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 11:06:00 volumio sudo[14003]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 18 11:06:00 volumio go-librespot[13973]: time="2025-04-18T11:06:00+02:00" level=debug msg="completed keyexchange" Apr 18 11:06:00 volumio mpd[13951]: Apr 18 11:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 18 11:06:00 volumio systemd[1]: Started Music Player Daemon. Apr 18 11:06:00 volumio sudo[13937]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio sudo[13910]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:00 volumio volumio[13784]: info: Shairport-Sync Started Apr 18 11:06:00 volumio volumio[13784]: Error adding Membership: Error: addMembership EINVAL Apr 18 11:06:00 volumio volumio[13784]: info: Shairport-Sync Started Apr 18 11:06:00 volumio volumio[13784]: info: Shairport-Sync Started Apr 18 11:06:00 volumio volumio[13784]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 11:06:00 volumio volumio[13784]: SPOTIFY: BQDcLW0SwvDrfvfeTWbVBwqiFS5guY16urofyASof2xXSk_bTdPLfLez1jw6oNZ9Z2r0ljIDmonUXNKcjeT1MI4i77QQPsBtarp4QlfHeZtj6ZKujezibWZg4dcamK49RVg_ssGelvCnAa5W9iTDl1dHjqhqSmP1m_fTvMUNEwRKl3OgvgtyXybvP7wCyhr_LyGYf2QgliDQAiSYLqhgNL5YxwUuPO95vtqVwy8A6lRnH4WlDu2WvFp8qZ4eXstT8JAzKctLwzEsHRrQgDk Apr 18 11:06:00 volumio volumio[13784]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 11:06:00 volumio volumio[13784]: info: New Spotify access token = BQDcLW0SwvDrfvfeTWbVBwqiFS5guY16urofyASof2xXSk_bTdPLfLez1jw6oNZ9Z2r0ljIDmonUXNKcjeT1MI4i77QQPsBtarp4QlfHeZtj6ZKujezibWZg4dcamK49RVg_ssGelvCnAa5W9iTDl1dHjqhqSmP1m_fTvMUNEwRKl3OgvgtyXybvP7wCyhr_LyGYf2QgliDQAiSYLqhgNL5YxwUuPO95vtqVwy8A6lRnH4WlDu2WvFp8qZ4eXstT8JAzKctLwzEsHRrQgDk Apr 18 11:06:00 volumio volumio[13784]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 18 11:06:00 volumio volumio[13784]: debug: API:printToastMessage Apr 18 11:06:00 volumio volumio[13784]: error: MPD error: The expression evaluated to a falsy value: Apr 18 11:06:00 volumio volumio[13784]: assert.ok(self.idling) Apr 18 11:06:00 volumio volumio[13784]: error: The expression evaluated to a falsy value: Apr 18 11:06:00 volumio volumio[13784]: assert.ok(self.idling) Apr 18 11:06:00 volumio volumio[13784]: verbose: New Socket.io Connection to 192.168.2.116 from 192.168.2.105 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 18 11:06:00 volumio volumio[13784]: info: MPD running with PID13951 Apr 18 11:06:00 volumio volumio[13784]: ,establishing connection Apr 18 11:06:00 volumio volumio[13784]: error: updateQueue error: null Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetVisibleSources Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:00 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:00 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 18 11:06:00 volumio volumio[13784]: info: Received Get System Info Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 18 11:06:00 volumio volumio[13784]: info: Discovery: Getting this device information Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:00 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:00 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:00 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:00 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:00 volumio volumio[13784]: info: Listing playlists Apr 18 11:06:00 volumio volumio[13784]: error: updateQueue error: null Apr 18 11:06:00 volumio volumio[13784]: SPOTIFY: User informations: {"country":"DE","display_name":"lemur30","email":"lemur30@gmx.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lemur30"},"followers":{"href":null,"total":12},"href":"https://api.spotify.com/v1/users/lemur30","id":"lemur30","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85fed857b2b5289d2be781bc6c","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82fed857b2b5289d2be781bc6c","width":64}],"product":"premium","type":"user","uri":"spotify:user:lemur30"} Apr 18 11:06:00 volumio volumio[13784]: info: Spotify Successfully logged in Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 11:06:00 volumio volumio[13784]: info: [1744967160986] CoreMusicLibrary::Adding element Spotify Apr 18 11:06:00 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 11:06:00 volumio volumio[13784]: Cannot find translation for source Jellyfin Apr 18 11:06:00 volumio volumio[13784]: Cannot find translation for source Spotify Apr 18 11:06:00 volumio volumio[13784]: debug: API:emitFavourites Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="completed challenge" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="authenticated as lemur30" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="authenticated as lemur30" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="dealer connection opened" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="initializing zeroconf session, username: lemur30" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="autoplay enabled: false" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="received connection id: Zjc5MjEyNDktMDljZS00MDBmLTg5NWEtZTgyM2EwMWJlMzc2K2RlYWxlcit0Y3A6Ly8wYWNhNWE1MS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQ0IxQzgzRTNFMTEwNDE0MERFREQ0QTA2Mjg5RDFEMEVERThCNTM4MjA5NjJCRjM2MTE5MDQ2NTVDNjE4MUM1Rg==" Apr 18 11:06:01 volumio go-librespot[13973]: time="2025-04-18T11:06:01+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,102]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,40]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,51]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,115]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,116]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,40]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,57]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,50]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,52]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Device check attempt 1/10 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI device ready signal received Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Calibrating... Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[0,0],"speeds":[100,100],"resolution":1} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Generated 2 positions Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Positions: [{"index":0,"value":0},{"index":1,"value":0}] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: First position: 0, Last position: 0 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[100,100],"speeds":[100,100],"resolution":1} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Generated 4 positions Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Positions: [{"index":0,"value":0},{"index":0,"value":16383},{"index":1,"value":0},{"index":1,"value":16383}] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: First position: 0, Last position: 16383 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,127,127] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,127,127] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[0,0],"speeds":[99,99],"resolution":1} Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 99.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 99.00 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Generated 164 positions Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: Positions: [{"index":0,"value":16383},{"index":0,"value":16181},{"index":0,"value":15978},{"index":0,"value":15776},{"index":0,"value":15574},{"index":0,"value":15372},{"index":0,"value":15169},{"index":0,"value":14967},{"index":0,"value":14765},{"index":0,"value":14563},{"index":0,"value":14360},{"index":0,"value":14158},{"index":0,"value":13956},{"index":0,"value":13754},{"index":0,"value":13551},{"index":0,"value":13349},{"index":0,"value":13147},{"index":0,"value":12945},{"index":0,"value":12742},{"index":0,"value":12540},{"index":0,"value":12338},{"index":0,"value":12136},{"index":0,"value":11933},{"index":0,"value":11731},{"index":0,"value":11529},{"index":0,"value":11327},{"index":0,"value":11124},{"index":0,"value":10922},{"index":0,"value":10720},{"index":0,"value":10517},{"index":0,"value":10315},{"index":0,"value":10113},{"index":0,"value":9911},{"index":0,"value":9708},{"index":0,"value":9506},{"index":0,"value":9304},{"index":0,"value":9102},{"index":0,"value":8899},{"index":0,"value":8697},{"index":0,"value":8495},{"index":0,"value":8293},{"index":0,"value":8090},{"index":0,"value":7888},{"index":0,"value":7686},{"index":0,"value":7484},{"index":0,"value":7281},{"index":0,"value":7079},{"index":0,"value":6877},{"index":0,"value":6675},{"index":0,"value":6472},{"index":0,"value":6270},{"index":0,"value":6068},{"index":0,"value":5866},{"index":0,"value":5663},{"index":0,"value":5461},{"index":0,"value":5259},{"index":0,"value":5056},{"index":0,"value":4854},{"index":0,"value":4652},{"index":0,"value":4450},{"index":0,"value":4247},{"index":0,"value":4045},{"index":0,"value":3843},{"index":0,"value":3641},{"index":0,"value":3438},{"index":0,"value":3236},{"index":0,"value":3034},{"index":0,"value":2832},{"index":0,"value":2629},{"index":0,"value":2427},{"index":0,"value":2225},{"index":0,"value":2023},{"index":0,"value":1820},{"index":0,"value":1618},{"index":0,"value":1416},{"index":0,"value":1214},{"index":0,"value":1011},{"index":0,"value":809},{"index":0,"value":607},{"index":0,"value":405},{"index":0,"value":202},{"index":0,"value":0},{"index":1,"value":16383},{"index":1,"value":16181},{"index":1,"value":15978},{"index":1,"value":15776},{"index":1,"value":15574},{"index":1,"value":15372},{"index":1,"value":15169},{"index":1,"value":14967},{"index":1,"value":14765},{"index":1,"value":14563},{"index":1,"value":14360},{"index":1,"value":14158},{"index":1,"value":13956},{"index":1,"value":13754},{"index":1,"value":13551},{"index":1,"value":13349},{"index":1,"value":13147},{"index":1,"value":12945},{"index":1,"value":12742},{"index":1,"value":12540},{"index":1,"value":12338},{"index":1,"value":12136},{"index":1,"value":11933},{"index":1,"value":11731},{"index":1,"value":11529},{"index":1,"value":11327},{"index":1,"value":11124},{"index":1,"value":10922},{"index":1,"value":10720},{"index":1,"value":10517},{"index":1,"value":10315},{"index":1,"value":10113},{"index":1,"value":9911},{"index":1,"value":9708},{"index":1,"value":9506},{"index":1,"value":9304},{"index":1,"value":9102},{"index":1,"value":8899},{"index":1,"value":8697},{"index":1,"value":8495},{"index":1,"value":8293},{"index":1,"value":8090},{"index":1,"value":7888},{"index":1,"value":7686},{"index":1,"value":7484},{"index":1,"value":7281},{"index":1,"value":7079},{"index":1,"value":6877},{"index":1,"value":6675},{"index":1,"value":6472},{"index":1,"value":6270},{"index":1,"value":6068},{"index":1,"value":5866},{"index":1,"value":5663},{"index":1,"value":5461},{"index":1,"value":5259},{"index":1,"value":5056},{"index":1,"value":4854},{"index":1,"value":4652},{"index":1,"value":4450},{"index":1,"value":4247},{"index":1,"value":4045},{"index":1,"value":3843},{"index":1,"value":3641},{"index":1,"value":3438},{"index":1,"value":3236},{"index":1,"value":3034},{"index":1,"value":2832},{"index":1,"value":2629},{"index":1,"value":2427},{"index":1,"value":2225},{"index":1,"value":2023},{"index":1,"value":1820},{"index":1,"value":1618},{"index":1,"value":1416},{"index":1,"value":1214},{"index":1,"value":1011},{"index":1,"value":809},{"index":1,"value":607},{"index":1,"value":405},{"index":1,"value":202},{"index":1,"value":0}] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: First position: 16383, Last position: 0 Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,127,127] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,127,127] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,53,126] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,53,126] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,106,124] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,106,124] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,32,123] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,32,123] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,86,121] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,86,121] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,12,120] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,12,120] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,65,118] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,65,118] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,119,116] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,119,116] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,45,115] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,45,115] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,99,113] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,99,113] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,24,112] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,24,112] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,78,110] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,78,110] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,4,109] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,4,109] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,58,107] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,58,107] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,111,105] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,111,105] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,37,104] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,37,104] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,91,102] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,91,102] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,17,101] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,17,101] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,70,99] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,70,99] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,124,97] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,124,97] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,50,96] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,50,96] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,104,94] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,104,94] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,29,93] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,29,93] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,83,91] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,83,91] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,9,90] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,9,90] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,63,88] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,63,88] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,116,86] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,116,86] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,42,85] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,42,85] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,96,83] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,96,83] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,21,82] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,21,82] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,75,80] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,75,80] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,1,79] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,1,79] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,55,77] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,55,77] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,108,75] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,108,75] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,34,74] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,34,74] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,88,72] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,88,72] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,14,71] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,14,71] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,67,69] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,67,69] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,121,67] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,121,67] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,47,66] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,47,66] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,101,64] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,101,64] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,26,63] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,26,63] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,80,61] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,80,61] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,6,60] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,6,60] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,60,58] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,60,58] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,113,56] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,113,56] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,39,55] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,39,55] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,93,53] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,93,53] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,19,52] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,19,52] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,72,50] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,72,50] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,126,48] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,126,48] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,52,47] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,52,47] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,106,45] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,106,45] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,31,44] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,31,44] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,85,42] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,85,42] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,11,41] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,11,41] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,64,39] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,64,39] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,118,37] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,118,37] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,44,36] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,44,36] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,98,34] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,98,34] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,23,33] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,23,33] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,77,31] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,77,31] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,3,30] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,3,30] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,57,28] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,57,28] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,110,26] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,110,26] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,36,25] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,36,25] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,90,23] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,90,23] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,16,22] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,16,22] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,69,20] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,69,20] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,123,18] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,123,18] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,49,17] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,49,17] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,103,15] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,103,15] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,28,14] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,28,14] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,82,12] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,82,12] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,8,11] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,8,11] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,62,9] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,62,9] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,115,7] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,115,7] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,41,6] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,41,6] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,95,4] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,95,4] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,21,3] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,21,3] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,74,1] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,74,1] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 11:06:01 volumio volumio[13784]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 11:06:01 volumio volumio[13784]: info: FaderController started successfully Apr 18 11:06:01 volumio volumio[13784]: info: [motorized_fader_control]: FaderController started successfully Apr 18 11:06:01 volumio volumio[13784]: info: [motorized_fader_control]: Starting service connections... Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Connected to Volumio at localhost:3000 Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: command/volumio/getAlbumInfo Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: command/volumio/getQueueInfo Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/playing Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/paused Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/stopped Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: fader/0/move Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: fader/0/move/end Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: validated/state Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/playing Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/paused Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: playback/stopped Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: fader/1/move Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: fader/1/move/end Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event registered: validated/state Apr 18 11:06:01 volumio volumio[13784]: info: [motorized_fader_control]: Plugin started successfully! Apr 18 11:06:01 volumio volumio[13784]: info: [motorized_fader_control]: -------------------------------------------------------------------- Apr 18 11:06:01 volumio volumio[13784]: info: Completed starting Core Plugins Apr 18 11:06:01 volumio volumio[13784]: info: ------------------------------------------- Apr 18 11:06:01 volumio volumio[13784]: info: ----- MyVolumio plugins startup ---- Apr 18 11:06:01 volumio volumio[13784]: info: ------------------------------------------- Apr 18 11:06:01 volumio volumio[13784]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 18 11:06:01 volumio volumio[13784]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 18 11:06:01 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:01 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:01 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967161784 Apr 18 11:06:01 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/stopped {"status":"stop","position":0,"title":"Monologue: Ike's Rap I","artist":"Isaac Hayes","album":"...To Be Continued","albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","seek":0,"duration":238,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":80,"dbVolume":null,"disableVolumeControl":false,"mute":false,"updatedb":false,"volatile":false,"service":"upnp_browser"} Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: info: go-librespot daemon successfully initialized Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:03 volumio volumio[13784]: error: error Apr 18 11:06:04 volumio sudo[13818]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:05 volumio volumio[13784]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 18 11:06:06 volumio volumio[13784]: info: Initializing connection to go-librespot Websocket Apr 18 11:06:06 volumio go-librespot[13973]: time="2025-04-18T11:06:06+02:00" level=debug msg="new websocket client" Apr 18 11:06:06 volumio volumio[13784]: info: Connection to go-librespot Websocket established Apr 18 11:06:06 volumio sudo[14059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 18 11:06:06 volumio sudo[14059]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:06 volumio sudo[14059]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:06 volumio sudo[14062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 18 11:06:06 volumio sudo[14062]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:06 volumio sudo[14062]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:06 volumio sudo[14065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 18 11:06:06 volumio sudo[14065]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:06 volumio sudo[14065]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:06 volumio volumio[13784]: info: Upmpdcli Daemon Started Apr 18 11:06:09 volumio volumio[13784]: info: Getting Spotify volume Apr 18 11:06:09 volumio volumio[13784]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 18 11:06:09 volumio volumio[13784]: info: Spotify volume: 100 Apr 18 11:06:09 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:09 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:09 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:09 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:06:09 volumio volumio[13784]: SPOTIFY: SPOTIFY VOLUME 100 Apr 18 11:06:09 volumio volumio[13784]: SPOTIFY: VOLUMIO VOLUME 80 Apr 18 11:06:09 volumio volumio[13784]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 18 11:06:09 volumio volumio[13784]: info: Setting Spotify Volume from Volumio: 80 Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin bluetooth to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin multiroom to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin metavolumio to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin cd_controller to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 18 11:06:10 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:10 volumio volumio[13784]: info: Starting MyVolumio Remote Streaming Endpoints Apr 18 11:06:10 volumio volumio[13784]: info: MyVolumio login type: Token Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 18 11:06:10 volumio volumio[13784]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 18 11:06:11 volumio volumio[13784]: info: Starting Streaming Service Transparent Proxy Apr 18 11:06:11 volumio volumio[13784]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 18 11:06:11 volumio volumio[13784]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 18 11:06:11 volumio volumio[13784]: info: Streaming services startup Apr 18 11:06:11 volumio volumio[13784]: info: Starting Streaming Daemon Apr 18 11:06:11 volumio sudo[14101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 18 11:06:11 volumio sudo[14101]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:11 volumio sudo[14101]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:11 volumio volumio[13784]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 18 11:06:11 volumio volumio[13784]: SPOTIFY: SETTING SPOTIFY VOLUME 80 Apr 18 11:06:11 volumio volumio[13784]: info: Sending Spotify command with payload to local API: /player/volume Apr 18 11:06:11 volumio go-librespot[13973]: time="2025-04-18T11:06:11+02:00" level=debug msg="update volume to 52428/65535" Apr 18 11:06:11 volumio volumio[13784]: error: Cannot start Volumio Streaming Daemon Apr 18 11:06:11 volumio volumio[13784]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 18 11:06:11 volumio volumio[13784]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 18 11:06:11 volumio go-librespot[13973]: time="2025-04-18T11:06:11+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 18 11:06:11 volumio go-librespot[13973]: time="2025-04-18T11:06:11+02:00" level=trace msg="emitting websocket event: volume" Apr 18 11:06:11 volumio volumio[13784]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Apr 18 11:06:11 volumio volumio[13784]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Apr 18 11:06:12 volumio volumio[13784]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 18 11:06:12 volumio volumio[13784]: STREAMING PROXY: Starting server on port 3245 Apr 18 11:06:12 volumio volumio[13784]: Node JS runtime: 14 Apr 18 11:06:13 volumio ntpd[744]: 188.245.32.133 local addr 192.168.2.116 -> Apr 18 11:06:13 volumio volumio[13784]: info: MyVolumio token set successfully Apr 18 11:06:13 volumio volumio[13784]: info: MYVOLUMIO: Adding device Apr 18 11:06:13 volumio volumio[13784]: info: MYVOLUMIO: Evaluating Server Apr 18 11:06:14 volumio volumio[13784]: info: MyVolumio status changed Apr 18 11:06:14 volumio volumio[13784]: info: Streaming services startup Apr 18 11:06:14 volumio volumio[13784]: info: Starting Streaming Daemon Apr 18 11:06:14 volumio volumio[13784]: info: Removing browser output: myVolumio user plan is not superstar Apr 18 11:06:14 volumio volumio[13784]: info: Removing audio output: Apr 18 11:06:14 volumio volumio[13784]: info: Stoppping Tunnel 1 Apr 18 11:06:14 volumio sudo[14126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 18 11:06:14 volumio sudo[14126]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:14 volumio sudo[14128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 18 11:06:14 volumio sudo[14128]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:06:14 volumio sudo[14126]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:14 volumio volumio[13784]: error: Cannot start Volumio Streaming Daemon Apr 18 11:06:14 volumio volumio[13784]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 18 11:06:14 volumio volumio[13784]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 18 11:06:14 volumio sudo[14128]: pam_unix(sudo:session): session closed for user root Apr 18 11:06:14 volumio volumio[13784]: info: Remote SSH Stopped Apr 18 11:06:14 volumio volumio[13784]: info: Setting Geolocation for MyVolumio to eu4 Apr 18 11:06:14 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:14 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:14 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:15 volumio volumio[13784]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 18 11:06:15 volumio volumio[13784]: info: Updating MyVolumio device info Apr 18 11:06:15 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:15 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:15 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:15 volumio volumio[13784]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 18 11:06:19 volumio volumio[13784]: info: MYVOLUMIO: Adding device Apr 18 11:06:19 volumio volumio[13784]: info: MYVOLUMIO: Evaluating Server Apr 18 11:06:19 volumio volumio[13784]: info: Setting Geolocation for MyVolumio to eu6 Apr 18 11:06:19 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:19 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:19 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:20 volumio volumio[13784]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 18 11:06:20 volumio volumio[13784]: info: Updating MyVolumio device info Apr 18 11:06:20 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:20 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:20 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:21 volumio volumio[13784]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 18 11:06:25 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 18 11:06:25 volumio volumio[13784]: debug: API:emitFavourites Apr 18 11:06:25 volumio volumio[13784]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 18 11:06:25 volumio volumio[13784]: info: CoreCommandRouter::volumioGetState Apr 18 11:06:25 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:06:25 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:06:29 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 11:06:29 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:29 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 18 11:06:30 volumio volumio[13784]: debug: API:emitFavourites Apr 18 11:06:30 volumio volumio-remote-updater[593]: No test mode Apr 18 11:06:30 volumio volumio-remote-updater[593]: No alpha test mode Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 18 11:06:30 volumio volumio[13784]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::volumioGetBrowseSources Apr 18 11:06:30 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 11:06:31 volumio volumio[13784]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 18 11:06:31 volumio volumio[13784]: info: Completed starting MyVolumio Plugin Apr 18 11:06:31 volumio volumio[13784]: [Metrics] CommandRouter: 36s 318.37ms Apr 18 11:06:31 volumio volumio[13784]: info: CoreCommandRouter::volumiosetStartupVolume Apr 18 11:06:31 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 11:06:31 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 11:06:31 volumio volumio[13784]: info: CoreCommandRouter::Close All Modals sent Apr 18 11:06:31 volumio volumio[13784]: debug: API:emitFavourites Apr 18 11:06:31 volumio volumio[13784]: info: CoreCommandRouter::Close All Modals sent Apr 18 11:06:31 volumio volumio[13784]: debug: API:emitFavourites Apr 18 11:06:32 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 18 11:06:32 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 18 11:06:32 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 18 11:06:38 volumio volumio[13784]: info: BOOT COMPLETED Apr 18 11:06:46 volumio ntpd[744]: 217.79.189.239 local addr 192.168.2.116 -> Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:06:55 volumio volumio[13784]: error: error Apr 18 11:07:05 volumio ntpd[744]: 129.70.132.33 local addr 192.168.2.116 -> Apr 18 11:07:18 volumio volumio[13784]: info: CoreCommandRouter::volumioSeek Apr 18 11:07:18 volumio volumio[13784]: info: CoreStateMachine::seek Apr 18 11:07:18 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:18 volumio volumio[13784]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","realUri":"upnp/folder/http://192.168.2.158:8200/ctl/ContentDir@1$7$AF7","type":"song","albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","artist":"Isaac Hayes","album":"...To Be Continued","name":"Monologue: Ike's Rap I","title":"Monologue: Ike's Rap I","duration":238} Apr 18 11:07:18 volumio volumio[13784]: info: CoreStateMachine::startPlaybackTimer Apr 18 11:07:18 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:18 volumio volumio[13784]: info: [1744967238177] ControllerUPNPBrowser::seek Apr 18 11:07:18 volumio volumio[13784]: info: ControllerMpd::seek Apr 18 11:07:18 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:18 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:18 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:18 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 11:07:18 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:18 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:18 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:18 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967238190 Apr 18 11:07:18 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/stopped {"status":"stop","position":0,"title":"Monologue: Ike's Rap I","artist":"Isaac Hayes","album":"...To Be Continued","albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","seek":175000,"duration":238,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":80,"dbVolume":null,"disableVolumeControl":false,"mute":false,"updatedb":false,"volatile":false,"service":"upnp_browser"} Apr 18 11:07:18 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:18 volumio volumio[13784]: error: [2@0] {seek} Bad song index Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPlay Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::play index undefined Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::startPlaybackTimer Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: info: [1744967239159] ControllerUPNPBrowser::clearAddPlayTrack Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand stop Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand stop took 2 milliseconds Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand clear Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand clear took 3 milliseconds Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: error: updateQueue error: null Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 9ms Apr 18 11:07:19 volumio volumio[13784]: error: updateQueue error: null Apr 18 11:07:19 volumio volumio[13784]: error: updateQueue error: null Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 181ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 177ms Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" took 2 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand play Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces system playlist update Apr 18 11:07:19 volumio volumio[13784]: info: Ignoring MPD Status Update Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 7ms Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand play took 5 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 5ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 4ms Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 7 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 6 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 5 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: info: Apr 18 11:07:19 volumio volumio[13784]: ---------------------------- MPD announces state update: player Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::getState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand status Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 9 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 4 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand status took 3 milliseconds Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseTrackInfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseTrackInfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseTrackInfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseState Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus stop Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus play Apr 18 11:07:19 volumio volumio[13784]: info: Received an update from plugin. extracting info from payload Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus play Apr 18 11:07:19 volumio volumio[13784]: info: Received an update from plugin. extracting info from payload Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 48ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 75ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 75ms Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 59 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 56 milliseconds Apr 18 11:07:19 volumio volumio[13784]: info: sendMpdCommand playlistinfo took 56 milliseconds Apr 18 11:07:19 volumio volumio[13784]: verbose: ControllerMpd::parseTrackInfo Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus play Apr 18 11:07:19 volumio volumio[13784]: info: Received an update from plugin. extracting info from payload Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus play Apr 18 11:07:19 volumio volumio[13784]: info: Received an update from plugin. extracting info from payload Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: ControllerMpd::pushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::servicePushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::syncState Apr 18 11:07:19 volumio volumio[13784]: info: CorePlayQueue::getTrack 0 Apr 18 11:07:19 volumio volumio[13784]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 11:07:19 volumio volumio[13784]: verbose: CURRENT POSITION 0 Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState stateService play Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::syncState currentStatus play Apr 18 11:07:19 volumio volumio[13784]: info: Received an update from plugin. extracting info from payload Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: CoreStateMachine::pushState Apr 18 11:07:19 volumio volumio[13784]: debug: CoreStateMachine::getState Apr 18 11:07:19 volumio volumio[13784]: info: CoreCommandRouter::volumioPushState Apr 18 11:07:19 volumio volumio[13784]: debug: API:pushState Apr 18 11:07:19 volumio volumio[13784]: debug: No callbacks for volumioPushState Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 154ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 147ms Apr 18 11:07:19 volumio volumio[13784]: info: ------------------------------ 147ms Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239550 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":"","album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.0008368200836820083 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0016736401673640166 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0016736401673640166],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239556 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239560 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239564 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239568 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":"","album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.11882845188284519 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.11882845188284519],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239572 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.11882845188284519 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.11882845188284519],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239576 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.11882845188284519 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.11882845188284519],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239580 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.12510460251046024 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.12510460251046024],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239598 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.11882845188284519 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.11882845188284519],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744967239602 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":282,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.11841004184100419 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.11841004184100419],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.11882845188284519 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.11882845188284519],"speeds":[100],"resolution":1} Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 11:07:19 volumio volumio[13784]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 11:07:19 volumio volumio[13784]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 11:07:19 volumio volumio[13784]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 11:07:19 volumio volumio[13784]: ReferenceError: self is not defined Apr 18 11:07:19 volumio volumio[13784]: at motorizedFaderControl.processFaderMoveQueue (/data/plugins/system_hardware/motorized_fader_control/index.js:1010:30) Apr 18 11:07:19 volumio volumio[13784]: at Timeout. (/data/plugins/system_hardware/motorized_fader_control/index.js:954:18) Apr 18 11:07:19 volumio volumio[13784]: at listOnTimeout (internal/timers.js:554:17) Apr 18 11:07:19 volumio volumio[13784]: at processTimers (internal/timers.js:497:7) Apr 18 11:07:19 volumio volumio[13784]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 11:07:20 volumio sudo[14479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-18 11:06 Apr 18 11:07:20 volumio sudo[14479]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"