×

INDI Library v2.0.6 is Released (02 Feb 2024)

Bi-monthly release with minor bug fixes and improvements

Help understanding the log - what happened here?

  • Posts: 643
  • Thank you received: 62
Hi!

I had another disastrous slew tonight, this time with the differential alignment option checked. Solver issues a slight slew and says alignment is successful, while the mount slews more than 90 degrees to the safety limit. THe job where this happes start at line 43979. It slews, then a long focusing sequence. THen solver starts in line 46685.

Log attached.

Magnus
Last edit: 3 years 10 months ago by Magnus Larsson.
3 years 10 months ago #54447
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 1119
  • Thank you received: 182
I had another problem, but perhaps related and compounded by a failure to complete the meridian flip the next night:
indilib.org/forum/ekos/7010-ekos-enters-...r-parking.html#54165
This also occurred only after Chris' changes that allow you northerly folks to image below the NCP.
Failure to flip is definitely a huge problem for everyone, irrespective of the latitude we are living at.
Jo
3 years 10 months ago #54449

Please Log in or Create an account to join the conversation.

  • Posts: 554
  • Thank you received: 138
I can see a solve reported ay #46743 giving an error of 6' 34" then differential slew to "12h 22m 47s" ( 12.3797 ) DE: " 04° 27' 56\"" ( 4.46567 )
The slew continues for some time and the hour angle changes from 1.65 to 11.968 see #47187 There's no evidence that a pier side change was requested, and no evidence of what the mount position now is.
Then at #47229 the mount status changes to slewing and the Ha starts reducing rapidly.
There's no indication that Ekos started this slew and it appears to think it should be acquiring an image, guising and imaging is started.
And at #47519 the log stops. The uncommanded slew is still running.

It would have helped a lot if there was some mount information in the log, or if the Gemini driver would report the position. It doesn't even seem to show any commands related to reading the position from the mount.
The following user(s) said Thank You: Jose Corazon
3 years 10 months ago #54463

Please Log in or Create an account to join the conversation.

  • Posts: 643
  • Thank you received: 62
Hi!

Thanks for having a look at it Chris!! THe slew that you are looking at there, did not "end". It ran into the safety limit, and there I extracted the log and manually stopped the process.

As for more info: what can I do? I've got driver log turned on for the mount in the Ekos log window as well as in the Indi window. What more settings should I turn on?

Magnus
3 years 10 months ago #54465

Please Log in or Create an account to join the conversation.

  • Posts: 554
  • Thank you received: 138
I was talking about two slews, the first to a Ha of 11.968, then the mount stops, acquisition starts and an uncommanded slew starts which looks as if it's going back to where it started.

There's nothing from the EKOS mount, That would at least shw if EKOS is doing anything. Otherwise maybe the Gemini driver author should be a little less mean with log information.
3 years 10 months ago #54468

Please Log in or Create an account to join the conversation.

  • Posts: 643
  • Thank you received: 62
Hi!

Yes, I see the start of the second slew, #47229. I have no clue to what started this. There are stuff about "Mount State" changing around this - anything related?

I've got Mount checked in Ekos, verbose, to file. Anything else I can do to produce more data?

Magnus
3 years 10 months ago #54470

Please Log in or Create an account to join the conversation.

Looks like Scope verbose debug is turned off by your configuration. Please turn it on in Options, then Save Configuration.
3 years 10 months ago #54474

Please Log in or Create an account to join the conversation.

  • Posts: 643
  • Thank you received: 62
Hi!

OK, scope verbose turned on. And here is what happened this night. To my mind similar stuff, while I was sleeping. Then there is a camera failure, but I know of that.



#81813
Start executing IX Lyr job

[2020-05-26T23:46:00.949 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Executing Job "IX Lyr"

#81835 Start slewing to target

[2020-05-26T23:46:02.089 CEST DEBG ][ org.kde.kstars.ekos.mount] - Slewing to RA= "18h 29m 41s" DEC= " 32° 15' 39\""
[2020-05-26T23:46:02.092 CEST DEBG ][ org.kde.kstars.indi] - ISD:Telescope sending coords RA: "18h 29m 41s" ( 18.4947 ) DE: " 32° 15' 39\"" ( 32.261 )
[2020-05-26T23:46:02.100 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'IX Lyr' is slewing to target."
[2020-05-26T23:46:02.137 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectRA> "
[2020-05-26T23:46:02.137 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:41#> "
[2020-05-26T23:46:02.139 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:41#> successful. "
[2020-05-26T23:46:02.139 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectDEC> "
[2020-05-26T23:46:02.139 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:15:40#> "
[2020-05-26T23:46:02.142 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:15:40#> successful. "
[2020-05-26T23:46:02.142 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <Slew> "
[2020-05-26T23:46:02.142 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:MS#> "
[2020-05-26T23:46:02.147 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <0> "
[2020-05-26T23:46:02.149 CEST INFO ][ org.kde.kstars.indi] - Losmandy Gemini : "[INFO] Slewing to RA: 18:29:41 - DEC: 32:15:40 "
[2020-05-26T23:46:02.789 CEST DEBG ][ org.kde.kstars.ekos.mount] - Mount status changed from "Tracking" to "Slewing"
[2020-05-26T23:46:02.791 CEST DEBG ][ org.kde.kstars.ekos.scheduler] - Mount State changed to 2
[2020-05-26T23:46:02.792 CEST DEBG ][ org.kde.kstars.ekos.scheduler] - Slewing stage...


#81931 Slew completed

[2020-05-26T23:46:09.010 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'IX Lyr' slew is complete."
[2020-05-26T23:46:09.019 CEST DEBG ][ org.kde.kstars.ekos.scheduler] - Mount State changed to 3

#81943 Foucsing
[2020-05-26T23:46:10.019 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'IX Lyr' is focusing."

#83679 Focus completed
[2020-05-26T23:48:47.298 CEST INFO ][ org.kde.kstars.ekos.focus] - "Autofocus complete after 15 iterations."

#83696 Plate solving

[2020-05-26T23:48:47.517 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'IX Lyr' is capturing and plate solving."

#83856 Slewing to target
[2020-05-26T23:49:03.957 CEST INFO ][ org.kde.kstars.ekos.align] - "Solver completed in 2 seconds."
[2020-05-26T23:49:03.959 CEST INFO ][ org.kde.kstars.ekos.align] - "Solver RA (277.26953) DEC (32.31194) Orientation (-98.51154) Pixel Scale (2.84286)"
[2020-05-26T23:49:03.975 CEST INFO ][ org.kde.kstars.ekos.align] - "Solution coordinates: RA (18h 29m 49s) DEC ( 32° 19' 32\") Telescope Coordinates: RA (18h 29m 40s) DEC ( 32° 15' 40\")"
[2020-05-26T23:49:03.976 CEST INFO ][ org.kde.kstars.ekos.align] - "Target is within 00° 04' 32\" degrees of solution coordinates."
[2020-05-26T23:49:03.985 CEST DEBG ][ org.kde.kstars.ekos.align] - Using differential slewing...
[2020-05-26T23:49:03.988 CEST DEBG ][ org.kde.kstars.indi] - ISD:Telescope sending coords RA: "18h 29m 30s" ( 18.4918 ) DE: " 32° 11' 47\"" ( 32.1966 )
[2020-05-26T23:49:03.989 CEST INFO ][ org.kde.kstars.ekos.align] - "Slewing to target coordinates: RA (18h 29m 30s) DEC ( 32° 11' 47\")."
[2020-05-26T23:49:03.998 CEST DEBG ][ org.kde.kstars.ekos.scheduler] - Align State "Slewing"
[2020-05-26T23:49:04.017 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectRA> "
[2020-05-26T23:49:04.017 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:30#> "
[2020-05-26T23:49:04.018 CEST INFO ][ org.kde.kstars.indi] - Atik 383L : "[INFO] CCD FOV rotation updated to -98.5115 degrees. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:30#> successful. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectDEC> "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:11:48#> "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:11:48#> successful. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <Slew> "
[2020-05-26T23:49:04.026 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:MS#> "
[2020-05-26T23:49:04.027 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <0> "
[2020-05-26T23:49:04.029 CEST INFO ][ org.kde.kstars.indi] - Losmandy Gemini : "[INFO] Slewing to RA: 18:29:30 - DEC: 32:11:48 "
[2020-05-26T23:49:04.781 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gv#> "
[2020-05-26T23:49:04.783 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <S> "
[2020-05-26T23:49:04.784 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GR#> "
[2020-05-26T23:49:04.786 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <18:29:41> "
[2020-05-26T23:49:04.786 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] VAL [18.4947] "
[2020-05-26T23:49:04.788 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GD#> "
[2020-05-26T23:49:04.791 CEST DEBG ][ org.kde.kstars.ekos.mount] - Mount status changed from "Tracking" to "Slewing"

But this slew is disastrous. Here it slews a long way and HA goes from several hours negative to positive

#84324
[2020-05-26T23:49:46.216 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <W>, lst 15.048340, ha 1.054451, pierSide 0 "

BUt the solver thinks it is successful:

#84334
[2020-05-26T23:49:47.222 CEST INFO ][ org.kde.kstars.ekos.align] - "Differential slewing complete. Astrometric solver is successful."
[2020-05-26T23:49:47.225 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gm#> "
[2020-05-26T23:49:47.225 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <W>, lst 15.048620, ha 1.099453, pierSide 0 "
[2020-05-26T23:49:47.242 CEST DEBG ][ org.kde.kstars.ekos.scheduler] - Align State "Complete"
[2020-05-26T23:49:47.242 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'IX Lyr' alignment is complete."

THen it starts guiding and tries to capture. Then another slew starts in the middle of this:

#84521
[2020-05-26T23:50:03.796 CEST DEBG ][ org.kde.kstars.ekos.mount] - Mount status changed from "Idle" to "Slewing"
[2020-05-26T23:50:03.797 CEST INFO ][ org.kde.kstars.ekos.guide] - "Mount is slewing. Aborting guide..."

I have no idea what this is


Log file attached, with the last 6 hours cut off (from midnight to morning)

Any ideas?

Magnus
3 years 10 months ago #54656
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 554
  • Thank you received: 138
Thanks for the log, it now has all the mount commands so we can see what is happening. The detailed analysis also helps.

The ra and dec from the mount before your disastrous slew look OK:
[2020-05-26T23:49:03.775 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GR#> "
[2020-05-26T23:49:03.777 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <18:29:40> "
[2020-05-26T23:49:03.777 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] VAL [18.4944] "
[2020-05-26T23:49:03.777 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GD#> "
[2020-05-26T23:49:03.778 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <+32:15:40> "
[2020-05-26T23:49:03.779 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] VAL [32.2611] "
[2020-05-26T23:49:03.779 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gm#> "
[2020-05-26T23:49:03.780 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <W>, lst 15.036521, ha -3.457923, pierSide 0 "

Then the slew is commanded:
[2020-05-26T23:49:04.017 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectRA> "
[2020-05-26T23:49:04.017 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:30#> "
[2020-05-26T23:49:04.018 CEST INFO ][ org.kde.kstars.indi] - Atik 383L : "[INFO] CCD FOV rotation updated to -98.5115 degrees. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sr 18:29:30#> successful. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <setObjectDEC> "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:11:48#> "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:Sd +32:11:48#> successful. "
[2020-05-26T23:49:04.025 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] <Slew> "
[2020-05-26T23:49:04.026 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:MS#> "
[2020-05-26T23:49:04.027 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <0> "
[2020-05-26T23:49:04.029 CEST INFO ][ org.kde.kstars.indi] - Losmandy Gemini : "[INFO] Slewing to RA: 18:29:30 - DEC: 32:11:48 "
[2020-05-26T23:49:04.781 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gv#> "
[2020-05-26T23:49:04.783 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <S> "

That all seems fine, the correct position is set, the slew started and the mount reports that it is slewing.

The slew completes, all the solver successful message means is that the solve and slew process has completed, it says nothing about the quality of the process.
[2020-05-26T23:49:47.211 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gv#> "
[2020-05-26T23:49:47.212 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <N> "
[2020-05-26T23:49:47.214 CEST INFO ][ org.kde.kstars.indi] - Losmandy Gemini : "[INFO] Slew is complete. Tracking... "
[2020-05-26T23:49:47.215 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GR#> "
[2020-05-26T23:49:47.215 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <13:56:57> "
[2020-05-26T23:49:47.215 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] VAL [13.9492] "
[2020-05-26T23:49:47.215 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] CMD <:GD#> "
[2020-05-26T23:49:47.218 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] RES <+32:11:48> "
[2020-05-26T23:49:47.218 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[SCOPE] VAL [32.1967] "
[2020-05-26T23:49:47.222 CEST INFO ][ org.kde.kstars.ekos.align] - "Differential slewing complete. Astrometric solver is successful."

And the position reached is incorrect in Ra, it's reached 13h 56m 57s when it was commanded to go to 18h 29m 30s. That's nearly 5 hours different.

Somebody more familiar with these mounts needs to look at this but it looks as if the mount controller is faulty in some way. It's gone to a position different to the one it was commanded to go to. It doesn't seem to be anthing that we can resolve.

After the bad slew tracking seems to be off. the Ra is changing by about 1 second a second.

There's nothing obvious that could start slewing but the mount seems to be reporting that it is slewing:
[2020-05-26T23:50:03.342 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gv#> "
[2020-05-26T23:50:03.344 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <S> "
[2020-05-26T23:50:03.344 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] CMD: <:Gv#> "
[2020-05-26T23:50:03.345 CEST DEBG ][ org.kde.kstars.indi] - Losmandy Gemini : "[DEBUG] RES: <S> "

The only possibility is the guiding commands.

Somebody more knowledgable than me needs to look at this.
The following user(s) said Thank You: Magnus Larsson
3 years 10 months ago #54660

Please Log in or Create an account to join the conversation.

  • Posts: 1119
  • Thank you received: 182
I may be completely off with this, so please have patience, but do tell me whether this is a completely dumb idea, please.

Could it be that the time-keeping in Kstars is off somehow?

The reason why I am saying this is that I know that Magnus is using a self-built focuser based on the MoonLite protocol and I started putting one together myself over the weekend. When I tested that, I noticed something strange. Look at the 3rd, i.e. last image in my post from the weekend:

indilib.org/forum/focusers-filter-wheels....html?start=48#54478

Look at the time stamp in the log window at the bottom and look at the (correct) time the system shows in the upper right corner of the window.

The times are way off. I am wondering whether the same thing is happening for Magnus and whether that messes up the mount positioning in his case.

Is that possible or is there another innocuous explanation why the time the focus module sees and the system time would be so radically different?

Jo

PS: Actually, Kstars shows the correct time (upper left corner of the KStars window, same as system time), but the MoonLite focus driver in the Control Panel has the time completely messed up. If that is a more general problem, I could imagine that that could translate into these strange mount slews Magnus is seeing. As his log shows, the RA position his mount ends up is >5 hrs different from the one it is supposed to be at. In my case, the MoonLite focus module thinks it is >3 hrs ahead of the system. Could there be a common cause for these two discrepancies?
Last edit: 3 years 10 months ago by Jose Corazon.
3 years 10 months ago #54676

Please Log in or Create an account to join the conversation.

  • Posts: 643
  • Thank you received: 62
Hi all!

Latest news on this: after a long stretch of testing, that is, Jasem doing the testing and me mostly watching, we found out that this is indeed a mount issue. It is reproducible in windows. We found out how to systematically reproduce it and could do in win to.
And: it is actually a known issue (seemingly not well communicated though). THere is a beta firmware, and it seems to solve the issue!! (this far)

So thanks all for helping me out with this, and again, particularly to Chris for fixing that irritating side-of-pier issue that had nothing to do with this!!

One happy amateur over here!

Magnus
The following user(s) said Thank You: Alfred, Eric
3 years 10 months ago #54689

Please Log in or Create an account to join the conversation.

  • Posts: 1119
  • Thank you received: 182
That's great news! What is the problem exactly and could this also explain the weird behaviour I am seeing with my iOptron mount?

Because I think it is unlikely that Chris' fix has anything to do with my iOptron issues either.
Last edit: 3 years 10 months ago by Jose Corazon.
3 years 10 months ago #54690

Please Log in or Create an account to join the conversation.

Time to create page: 0.699 seconds