×

INDI Library v2.0.7 is Released (01 Apr 2024)

Bi-monthly release with minor bug fixes and improvements

Help understanding the log - what happened here?

  • 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.

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

I'm not really sure what causes the problem, but it manifests as small adjustments in RA, about 10", at times casuses real runaway slews. What causes this is beyond me, but clearly a firmware issue.

As this is Gemini-firmware, I don't hink it can be realted to your iOptron issue.

Magnus
The following user(s) said Thank You: Jose Corazon
3 years 10 months ago #54699

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

  • Posts: 1029
  • Thank you received: 301
I was wondering too if the telescope location could have been an issue here, but while two *different* locations are set in sequence, that information does not seem wrong (near the Malmö airport for both).

Jo, it seems the indiserver in your screenshot did not succeed in updating its local time. This will certainly break stuff related to LST for the mount.

As an example, for an unknown reason, my setup recently lost its geographical location setting. While it simply shifted longitude to Greenwich, which is quite close to my location (1 degree), the latitude went down to the equator. Because of this, altitude of NCP went to 3 small degrees from the point of view of the mount. The unexpected side-effect was that the safety zone configured for the horizon triggered at surprising places to stop mount tracking. And Ekos/Scheduler is not that good at restoring tracking...

In any case, congratulations to Jasem for this live debugging!

-Eric
The following user(s) said Thank You: Jose Corazon
3 years 10 months ago #54702

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

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

Two different locations? How do you mean, in my log files?

Yeah, a huge thanks to Jasem and to Chris!!!

Magnus
3 years 10 months ago #54707

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

  • Posts: 554
  • Thank you received: 138
Yes, once we could extract a log showing the relevant information i.e. what commands were sent to the mount and what it did it was obvious. Absolutely nothng to do with Ekos. Everything to do with the mount.

The thing to remember is that correlation does not imply causation. Two things happening together need not be related.

None the less I think the Meridian flip enhancements should go. I am sick and tired of having to waste time defending them from random posts blaming them for everything except possibly bad weather.

Perhaps you should all start thinking before posting fake news.
The following user(s) said Thank You: Jose Corazon, Jim S.
3 years 10 months ago #54721

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

  • Posts: 62
  • Thank you received: 9

I am a future G11 user (as soon as I save a few more pennies :) ) Anyway I have read a few other posts on the Losmandy user group after following this post. Thank you all for the heads up Chris, Jasem and Magnus !

groups.io/g/Losmandy_users/topic/29574555#62167

groups.io/g/Losmandy_users/topic/32858271#63456
Celestron CGX, QSI683 Astrodon Gen 2 E series LRGB, Ha, OIII, ES102CF, ZWO-ASI178MC, 60mm guide scope, Pegasus Focus Cube 2, Feather Touch Focuser.
3 years 10 months ago #54722

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

Time to create page: 0.520 seconds