indilib / indi-3rdparty

INDI 3rd Party drivers repository
https://www.indilib.org/devices.html
GNU Lesser General Public License v2.1
124 stars 208 forks source link

Nexdome driver not slew to new AZ without "Abort" being sent - waiting on wrong dome response? #179

Closed xthestreams closed 4 years ago

xthestreams commented 4 years ago

Describe the bug In indi_nexdome, per the thread on INDI forum, the following bug appears to be specific to the Nexdome driver - taken from MarkG's original post

https://indilib.org/forum/general/6272-nexdome-driver-will-not-slave-dome-without-abort-press.html

Per Jassem's concern re: the base class, there appears to be a second bug with the Simulator whereby it does not slew at all until EKOS is disconnected and re-started.

To Reproduce Exact steps to reproduce the behavior. "The dome will move to slave one time after unparking the mount but not after that. Also the manual CCW and CW buttons in the driver will work once only. Until, that is, the abort button is pressed, where the dome will then move to the correct mount azimuth. Similarly the CW & CCW buttons will again move the dome once, after each abort button press."

Expected behavior The dome should slew as teh mount changes azimuth angles.

Screenshots N/A - a movie can be provided if required.

Desktop (please complete the following information):

Log Files Make sure to enable logging and include log files https://indilib.org/support/logs-submission.html

knro commented 4 years ago

Can you enable INDI+Dome logging and share these. I just tested with simulators again and I cannot reproduce this behavior. The dome was following the mount motion during GOTOs and also while tracking. I kept it now for 2 hours and the Dome Simulator behaves normally.

xthestreams commented 4 years ago

I can only imagine your frustrations! I left the dome synched and running for a while, that's what you can see right before I press "Abort" - prior to that teh dome had been at 73" which was where the scope was pointing when EKOS was started.

[2020-08-04T11:01:47.600 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788374102948339,-15.48422212877864|No error. Error = 0. " [2020-08-04T11:01:47.602 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:01:48.601 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:01:51.734 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788374247628994,-15.484228199712987|No error. Error = 0. " [2020-08-04T11:01:51.734 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:01:52.734 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:01:54.001 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event Online> with value " [2020-08-04T11:01:55.752 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788374547672184,-15.484233754263613|No error. Error = 0. " [2020-08-04T11:01:55.754 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:01:56.111 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event <:BV946#> with value <946> " [2020-08-04T11:01:56.753 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:01:57.658 AEST INFO ][org.kde.kstars.ekos.observatory] - "Aborting..." [2020-08-04T11:01:57.667 AEST INFO ][org.kde.kstars.ekos.observatory] - "Aborting..." [2020-08-04T11:01:57.676 AEST DEBG ][ org.kde.kstars.ekos] - Aborting... [2020-08-04T11:01:58.624 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] CMD <@SWR> " [2020-08-04T11:01:58.670 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] RES <:SER,11169,0,55080,28228,300> " [2020-08-04T11:01:58.672 AEST DEBG ][org.kde.kstars.ekos.observatory] - Setting dome status to 0 [2020-08-04T11:01:58.672 AEST INFO ][org.kde.kstars.ekos.observatory] - "Dome is idle." [2020-08-04T11:01:59.820 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.7883747416805,-15.484240150889661|No error. Error = 0. " [2020-08-04T11:01:59.822 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:02:00.160 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] JD: 2.45907e+06 - MSD: 21.9043 " [2020-08-04T11:02:00.161 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] MC.x: 0 - MC.y: -0.1 MC.z: 0.25 " [2020-08-04T11:02:00.161 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] HA: -4.22581 Lng: 144.874 RA: 176.826 " [2020-08-04T11:02:00.162 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OTA_SIDE: 1 " [2020-08-04T11:02:00.162 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OTA_OFFSET: 0.6 Lat: -37.8414 " [2020-08-04T11:02:00.162 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OC.x: -0.268776 - OC.y: 0.229089 OC.z: -0.173627 " [2020-08-04T11:02:00.163 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Mount Az: 86.4133 Alt: 30.3116 " [2020-08-04T11:02:00.163 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OV.x: 0.861603 - OV.y: 0.0540072 OV.z: 0.504702 " [2020-08-04T11:02:00.163 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Calculated target azimuth is 71.7259. MinAz: 53.6735, MaxAz: 89.7783 " [2020-08-04T11:02:00.163 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] CMD <@GAR,71> " [2020-08-04T11:02:00.235 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] RES <:left> " [2020-08-04T11:02:00.238 AEST INFO ][ org.kde.kstars.indi] - NexDome : "[INFO] Dome is moving to position 71.7259 degrees... " [2020-08-04T11:02:00.238 AEST DEBG ][org.kde.kstars.ekos.observatory] - Setting dome status to 2 [2020-08-04T11:02:00.238 AEST INFO ][org.kde.kstars.ekos.observatory] - "Dome is moving counter clockwise..." [2020-08-04T11:02:00.248 AEST INFO ][ org.kde.kstars.indi] - NexDome : "[INFO] Dome is syncing to position 71.7259 degrees... " [2020-08-04T11:02:00.441 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <11165> " [2020-08-04T11:02:00.725 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <11136> " [2020-08-04T11:02:00.820 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:02:01.008 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <11080> " [2020-08-04T11:02:01.291 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10999> " [2020-08-04T11:02:01.573 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10926> " [2020-08-04T11:02:01.856 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10880> " [2020-08-04T11:02:02.114 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event <:SER,10863,0,55080,28228,300#> with value <10863,0,55080,28228,300> " [2020-08-04T11:02:02.380 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event Online> with value " [2020-08-04T11:02:03.981 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788374933954906,-15.48424628727156|No error. Error = 0. " [2020-08-04T11:02:03.982 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:02:04.982 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:02:08.052 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788375198290197,-15.48425197741355|No error. Error = 0. " [2020-08-04T11:02:08.054 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:02:08.637 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Updated telescope Az: 86.3905 - Alt: 30.3395 " [2020-08-04T11:02:09.056 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:02:10.246 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event Online> with value " [2020-08-04T11:02:12.102 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788375429158748,-15.484258456304929|No error. Error = 0. " [2020-08-04T11:02:12.103 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:02:13.102 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:02:16.277 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788373498938562,-15.484216410237593|No error. Error = 0. " [2020-08-04T11:02:16.278 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:02:17.278 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:02:18.367 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event Online> with value "

xthestreams commented 4 years ago

I've trimmed a third iteration of the "abort" sequence" from my testing. From what I can see below, it would appear that there is no "STOP" event - which is consistent with the published API. Instead a SER event is issued with the estimated AZ of the dome - in essence the driver is waiting for a message that never comes.

[2020-08-04T11:37:17.627 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] CMD <@SWR> " [2020-08-04T11:37:17.678 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] RES <:SER,10863,0,55080,28228,300> " [2020-08-04T11:37:17.680 AEST DEBG ][org.kde.kstars.ekos.observatory] - Setting dome status to 0 [2020-08-04T11:37:17.680 AEST INFO ][org.kde.kstars.ekos.observatory] - "Dome is idle." [2020-08-04T11:37:17.909 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event <:SWR#> with value " [2020-08-04T11:37:18.586 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788381848028244,-15.484097701067697|No error. Error = 0. " [2020-08-04T11:37:18.588 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:37:19.161 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] JD: 2.45907e+06 - MSD: 22.4945 " [2020-08-04T11:37:19.162 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] MC.x: 0 - MC.y: -0.1 MC.z: 0.25 " [2020-08-04T11:37:19.162 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] HA: -3.63557 Lng: 144.874 RA: 176.826 " [2020-08-04T11:37:19.163 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OTA_SIDE: 1 " [2020-08-04T11:37:19.164 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OTA_OFFSET: 0.6 Lat: -37.8414 " [2020-08-04T11:37:19.164 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OC.x: -0.348135 - OC.y: 0.19979 OC.z: -0.135911 " [2020-08-04T11:37:19.164 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Mount Az: 80.439 Alt: 37.2548 " [2020-08-04T11:37:19.164 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] OV.x: 0.784895 - OV.y: 0.132206 OV.z: 0.60536 " [2020-08-04T11:37:19.164 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Calculated target azimuth is 62.7948. MinAz: 41.8899, MaxAz: 83.6997 " [2020-08-04T11:37:19.167 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] CMD <@GAR,62> " [2020-08-04T11:37:19.243 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] RES <:left> " [2020-08-04T11:37:19.246 AEST INFO ][ org.kde.kstars.indi] - NexDome : "[INFO] Dome is moving to position 62.7948 degrees... " [2020-08-04T11:37:19.246 AEST DEBG ][org.kde.kstars.ekos.observatory] - Setting dome status to 2 [2020-08-04T11:37:19.246 AEST INFO ][org.kde.kstars.ekos.observatory] - "Dome is moving counter clockwise..." [2020-08-04T11:37:19.258 AEST INFO ][ org.kde.kstars.indi] - NexDome : "[INFO] Dome is syncing to position 62.7948 degrees... " [2020-08-04T11:37:19.587 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:37:19.695 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10858> " [2020-08-04T11:37:19.978 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10828> " [2020-08-04T11:37:20.260 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10771> " [2020-08-04T11:37:20.545 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10688> " [2020-08-04T11:37:20.829 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10579> " [2020-08-04T11:37:21.117 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10442> " [2020-08-04T11:37:21.394 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10288> " [2020-08-04T11:37:21.677 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <10133> " [2020-08-04T11:37:21.956 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9979> " [2020-08-04T11:37:22.240 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9830> " [2020-08-04T11:37:22.523 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9708> " [2020-08-04T11:37:22.688 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] RES: 11.788382129032215,-15.484099398924258|No error. Error = 0. " [2020-08-04T11:37:22.693 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[SCOPE] Current RA: 11:47:18 Current DEC: -15:29:03 " [2020-08-04T11:37:22.777 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event Online> with value " [2020-08-04T11:37:23.058 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9611> " [2020-08-04T11:37:23.341 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9542> " [2020-08-04T11:37:23.624 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event with value <9500> " [2020-08-04T11:37:23.692 AEST DEBG ][ org.kde.kstars.indi] - Paramount : "[DEBUG] CMD: / Java Script /var Out;sky6RASCOMTele.GetRaDec();Out = String(sky6RASCOMTele.dRa) + ',' + String(sky6RASCOMTele.dDec); " [2020-08-04T11:37:23.881 AEST DEBG ][ org.kde.kstars.indi] - NexDome : "[DEBUG] Processing event <:SER,9486,0,55080,28228,300#> with value <9486,0,55080,28228,300> "

xthestreams commented 4 years ago

I've had a detailed look at the logs and the command/event protocol for the dome and it appears that the driver is waiting for a response that never comes. I have tried changing the STOP command text to be the SER, text but this has not helped, so perhaps the bug lies deeper as Jassem suggests. As soon as Abort is issued the driver returns to an "IDLE" state and starts responding to commands again - I'd love to find a simple workaround but most of the logic hacks I have tried have not worked.

xthestreams commented 4 years ago

do we think it might have something to do with the fact that Nexdome can issue asynchronous status messages?

knro commented 4 years ago

Best thing right now is to set teamviewer and send me credentials so I can login and debug this directly there. Send credential to support@stellarmate.com

xthestreams commented 4 years ago

are you saying my coding skills are terrible?! ;-) happy to do so, I would much rather solve problems than create problems, but I'm still feeling my way around the INDI codebase and re-learning C++ so probably not the best person to be messing around.

xthestreams commented 4 years ago

Sent!

knro commented 4 years ago

I actually didn't receive anything yet, please resend.

xthestreams commented 4 years ago

just resent

knro commented 4 years ago

This specific issue should now be fixed with the latest changes.

xthestreams commented 4 years ago

working great! @knro I don't know how to thank you enough!