×

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

Bi-monthly release with minor bug fixes and improvements

30 sec delay on align module

  • Posts: 219
  • Thank you received: 41
I'm using the current version of KStars on macOS 10.14.4 with an EQMod driver (connected via wifi with an AZ-GTi mount), a ZWO ASI120MM-S CCD and Canon DSLR 40D camera. I was able to run all the modules, but I've a problem with the align module: every time, the module tries to get a new picture, I get a beachball cursor and all the system hangs by about 30 sec (the time is variable, around 30 sec). KStats is also blocked while the freeze is in place.

I've extracted the log around the instant of the failure:
[2019-12-23T20:50:18.848 CET INFO ][           org.kde.kstars.indi] - Canon DSLR EOS 40D (PTP mode) :  "[INFO] Saving device configuration... "
[2019-12-23T20:50:18.850 CET INFO ][           org.kde.kstars.indi] - Canon DSLR EOS 40D (PTP mode) :  "[INFO] Device configuration saved. "
[2019-12-23T20:50:28.460 CET INFO ][     org.kde.kstars.ekos.align] - "World Coordinate System (WCS) is enabled. CCD rotation must be set either manually in the CCD driver or by solving an image before proceeding to capture any further images, otherwise the WCS information may be invalid."
[2019-12-23T20:50:28.493 CET INFO ][           org.kde.kstars.indi] - ZWO CCD ASI120MM-S :  "[INFO] World Coordinate System is enabled. "
[2019-12-23T20:50:40.496 CET INFO ][     org.kde.kstars.ekos.align] - Starting Polar Alignment Assistant process...
[2019-12-23T20:50:40.496 CET INFO ][     org.kde.kstars.ekos.align] - "Clearing mount Alignment Model..."
[2019-12-23T20:51:10.542 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T20:51:10.542 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T20:51:10.555 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
 
......
 
[2019-12-23T21:02:04.153 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=A70080\", 8 bytes read "
[2019-12-23T21:02:34.905 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:02:34.905 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:02:34.914 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:02:34.915 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
 
......
 
[2019-12-23T21:02:48.404 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] dispatch_command: \":d1\", 4 bytes written "
[2019-12-23T21:02:48.407 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=740080\", 8 bytes read "
[2019-12-23T21:02:48.408 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] dispatch_command: \":d2\", 4 bytes written "
[2019-12-23T21:02:48.414 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=900080\", 8 bytes read "
[2019-12-23T21:03:18.907 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:03:18.908 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:03:18.917 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:03:18.918 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
 
......
 
[2019-12-23T21:03:27.506 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] dispatch_command: \":d2\", 4 bytes written "
[2019-12-23T21:03:27.507 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=8F0080\", 8 bytes read "
[2019-12-23T21:03:58.007 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:03:58.007 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:03:58.016 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:03:58.017 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
 
......
 
[2019-12-23T21:04:05.339 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] dispatch_command: \":d2\", 4 bytes written "
[2019-12-23T21:04:05.340 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=8F0080\", 8 bytes read "
[2019-12-23T21:04:35.848 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:04:35.852 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:04:35.861 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:04:35.862 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
[2019-12-23T21:04:35.939 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[SCOPE] Compute local time: lst=2.18108480 ( 2:10:51.91) - julian date=2458841.33617189 "
 
......
 
[2019-12-23T21:04:42.554 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=8F0080\", 8 bytes read "
[2019-12-23T21:05:13.056 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:05:13.057 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:05:13.066 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:05:13.066 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
 
......
 
[2019-12-23T21:05:19.790 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=8F0080\", 8 bytes read "
[2019-12-23T21:05:50.279 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:05:50.279 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-23T21:05:50.288 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-23T21:05:50.289 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
[2019-12-23T21:05:50.364 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[SCOPE] Compute local time: lst=2.20181871 ( 2:12:06.55) - julian date=2458841.33703344 "

As you can see, after each pause the same two debug lines appear:
[2019-12-23T21:03:58.007 CET DEBG ][                       default] - "astropy (3.2.3)\nnumpy (1.17.4)\npip (7.1.2)\nsetuptools (18.3.1)\nwheel (0.26.0)\n"
[2019-12-23T21:03:58.007 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.

I've tried the same computer with the simulators and no pause, no warning error appears :(

So, anybody has experienced similar problems? Any clue about what can I investigate?

Thanks in advance!
4 years 3 months ago #47203

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

  • Posts: 219
  • Thank you received: 41
At the end it was a physical problem with the computer. I suspect that one USB port is damaged. I tried exactly the same configuration with another computer and all worked as expected.

Now, I can say that Ekos and all the INDI ecosystem in general, is a bless. Now I’ve a portable full automated astro photography rig.

Yes the learning curve is a little steeped, but once you understand your way inside the different components, the power of automation inside Ekos is impressive.

Thank you to all the collaborator on this project for gift us with such a magnificent tool!

4 years 3 months ago #47283

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

  • Posts: 1185
  • Thank you received: 370
A warm welcome to the INDI / KStars community :-)
4 years 3 months ago #47295

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

  • Posts: 219
  • Thank you received: 41
Thank you for the warm reception to the comunity. Unforunatly my hope were infundaded. Yesterday I was able to enjoy 3h under the stars and all modules worked as expected: polar aligment, guide and long time exposures without any hiccup. As I've changed the computer I suspected that something was wrong with the old one (a MacBookAir). But today, with exactly the same setup that yesterday, on the same new computer that yesterday (a MacBookPro), the odd 30sec delay reapear.

Looking at the logs, it's seems related with astrometry.net in align module. If I go to the focus module and I try to use the CCD camera, it respon instantanously and I can take images as will.

But on the align module each time a new image must be shot, a 30 sec delay, with a beach ball cursor and the UI frozes. I've tried the align module with a DSLR on the main telescope and the same 30sec pause happens. On the other side if I change astrometry.net by ASTAP the response (image capture) is instatanous (no, I can't use ASTAP because my guide CCD is very small, with only 960px and ASTAP needs at least 1000px so the alignmen always fails)

So I need some help to diagnose and solve this nasty problem. I've attached all the logs, so you can see the delay always happens before the "Package version/QProcess" message are printed:
[2019-12-27T19:29:36.148 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[COMM] read_eqmod: \"=AB0080\", 8 bytes read "
[2019-12-27T19:30:06.224 CET DEBG ][                       default] - "Package    Version\n---------- -------\nastropy    3.2.3  \nnumpy      1.17.4 \npip        19.2.3 \nsetuptools 41.4.0 \nwheel      0.33.6 \n"
[2019-12-27T19:30:06.224 CET WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
[2019-12-27T19:30:06.230 CET DEBG ][           org.kde.kstars.indi] - IndiCCD: capture() CCD
[2019-12-27T19:30:06.231 CET INFO ][     org.kde.kstars.ekos.align] - "Capturing image..."
[2019-12-27T19:30:06.304 CET DEBG ][           org.kde.kstars.indi] - EQMod Mount : "[SCOPE] Compute local time: lst=0.86504751 ( 0:51:54.17) - julian date=2458845.27056457 "

File Attachment:

File Name: 2019-12-27.zip
File Size:364 KB
Last edit: 4 years 3 months ago by Rafa Barberá.
4 years 3 months ago #47296
Attachments:

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

  • Posts: 1185
  • Thank you received: 370
Could you please upload the entire log file? I'll take a look...
The following user(s) said Thank You: Rafa Barberá
4 years 3 months ago #47297

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

  • Posts: 219
  • Thank you received: 41
I was editing the message because I've seen that I've forgotten it :)
4 years 3 months ago #47298

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

  • Posts: 1185
  • Thank you received: 370
Did you intentionally align with the ASI-120mm-s? Capturing the image during the alignment worked fine but it might be that it interferes with guiding.

- Wolfgang
4 years 3 months ago #47300

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

  • Posts: 219
  • Thank you received: 41
Yes i was trying to use the ASI120MM-S to align/guide and the main telescope with DSLR to imaging. But please, ignore all the guiding calibration. Latter, around time stamp 2019-12-27T19:29:36.148, you can see that all the alignments have a 30sec pause. Ar this time, no camera was trying to capture any image, other that the ASI120MM-S in the align module
4 years 3 months ago #47302

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

  • Posts: 1185
  • Thank you received: 370
OK, now I can see it. One thing that looks unusual: it looks like the EQMOD driver logs excessively. Could you please check which value is set as the polling period of your mount? I would recommend to set it to a value of 500ms or more.

If this does not help, I would at least try to set logging level to INFO. Maybe the explanation is simply excessive logging that leads to some blocking.

- Wolfgang
The following user(s) said Thank You: Rafa Barberá
4 years 3 months ago #47304

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

  • Posts: 219
  • Thank you received: 41
I’ll review the pooling interval, but I’m pretty sure that the login has no relation with the problem, because it was disabled when the problem started. I’ve started the logs just to be able to show the behavior. For me is very suspicious the message

WARN ][                       default] - QProcess: Destroyed while process ("/usr/local/bin/pip3") is still running.
.
4 years 3 months ago #47305

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

  • Posts: 1185
  • Thank you received: 370
Hm, maybe that blocks the INDI client of EKOS. No clue where this comes from.
4 years 3 months ago #47306

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

  • Posts: 219
  • Thank you received: 41


Looking for info about this error, I’ve found this entry on stackoverflow

stackoverflow.com/questions/14504201/ddg#14505682

So my “30 sec freeze” seems related with a sync problem between Ekos and astrometry.net
4 years 3 months ago #47307

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

Time to create page: 0.346 seconds