First I want to thank you for a wonderful piece of software! It is a tremendous resource for astrophotograhers!
I'm using AstroTortilla with BackYardEOS on an Astro-Physics Mach1 mount on a Windows 10 laptop with no problems with the Astro-Physics v2 ASCOM driver.
With APCC running, AstroTortilla does not work anymore, slowing down tremendously and stopping completely.
I corresponded with the developer of APCC, Ray Gralak, to take a look at this and here are his replies:
Astrotortilla is just saturating the bandwidth
of the driver with its large number of queries per second.
It looks like AstroTortilla is polling the driver for connected status every 10-20 milliseconds
(50-100x a second). Astrotorilla is probably slowing down because the driver
can't always respond because of background tasks communicated with APCC. So,
the short answer is to ask the Astrotortilla developers if they can slow
down polling to a sane level so that their program will be more responsive.
There is no need to poll the mount 50-100x for connected status, when once,
or even just a few times per second would do.
So, the problem here has nothing to do with APCC but entirely with the way
AstroTortilla is polling. They are killing their own application's user
interface performance because of how often they poll. Another way they could
have kept the user interface more responsive while madly polling would have
been to use a background thread to poll the driver.
If Astrotortilla moved its polling to a background thread then the user
interface would never be affected by even short duration user interface
lockups. I recommend that they do that and also reduce the polling rate
significantly. It doesn't need to know to the nearest 1--20 milliseconds
when the driver is connected or not. In fact by the ASCOM standards the
Connected status does not change if the serial port goes down, so it serves
absolutely no purpose whatsoever!
Would there be any way to get AstroTortilla to poll less frequently or use a background thread to poll the driver?
Thanks again for a great piece of software!
Jerry Lodriguss
www.astropix.com
Last edit: Jerry Lodriguss 2016-04-13
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
There should be a setting to increment the polling cache duration for badly behaving mount drivers. AT typically polls about once every few seconds to update the UI values, don't know why it should happen more frequently on your setup.
The typical root cause in those cases is a non-compliant ASCOM device driver, which passes all queries directly to the hardware. That behavior is explicitly listed as bad behavior in the ASCOM specs, which AT adheres to.
--Antti
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
This is Ray Gralak, the author of the Astro-Physics V2 ASCOM driver and also APCC. Although I understand your response above I have analyzed the driver log files and I don't think it's the driver's fault that AstroTortilla user interface sometimes responds slowly when connected. Note that APCC and the driver are not acting slowly, only AstroTortilla (AT), and here is what I think is happening based on the logs.
First, AT is the only application I've ever heard of that slows down when using the AP driver+APCC.
Second, as evidence of the origin of possible "bad behavior" at the end of this post is a clip of the AP V2 driver log I captured. The only application polling the ASCOM "Connected" property was AT as it was the only application connected to the driver. AT is trying to poll the ASCOM "Connected" property every 10-20 milliseconds. The offending calls in the log clip are those with "GET Connected = True". There are time stamps to the nearest millisecond on each line so you can see the timing. What is unknown is the overhead of COM interop from AT's point of view, it could be longer than the timing intervals suggest. You would have to put timers in AT to measure that.
Since almost all ASCOM drivers are Single Apartment threaded, including the AP V2 driver, there is only one thread supporting all calls and background actions. The AP V2 driver runs background timers to poll and cache important state information. During that polling if an ASCOM client communicates with it then the client might have to wait in line because of the way COM interop serializes requests.
So here is what I think is the problem... if AT is accessing the driver on AT's user interface thread instead of a background thread then while waiting for a response from the driver AT's user interface might appear to lock up until the response is returned. If this is happening often enough, then to the user this might make AT appear to act slow because of the tiny pauses.
If AT could use a background thread then AT's UI would not be blocked while it waits and thus user interface actions would never appear to be slow. Or, if AT could reduce the poll rate of the "Connected" property then AT's UI would also not appear to be slow under those same conditions. I think AT should only need to poll "Connected" once, or at most twice, a second.
Here is the log clip:
050628 2016-04-12 18:39:26.552: ASCOM: Info : GET Connected = True
050629 2016-04-12 18:39:26.563: ASCOM: Info : GET Connected = True
050630 2016-04-12 18:39:26.574: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050631 2016-04-12 18:39:26.753: Driver: Info : CommandString TX=':GR#'
050632 2016-04-12 18:39:26.764: ASCOM: Info : GET Connected = True
050633 2016-04-12 18:39:26.976: Driver: Info : CommandString: APCC response: ':APCC,5163,GR#', Response='09:19:28.3#'
050634 2016-04-12 18:39:26.989: ASCOM: Info : GET Connected = True
050635 2016-04-12 18:39:27.001: ASCOM: Info : GET Connected = True
050636 2016-04-12 18:39:27.012: ASCOM: Info : GET Connected = True
050637 2016-04-12 18:39:27.023: ASCOM: Info : GET Connected = True
050638 2016-04-12 18:39:27.034: ASCOM: Info : GET Connected = True
050639 2016-04-12 18:39:27.066: ASCOM: Info : GET Connected = True
050640 2016-04-12 18:39:27.079: ASCOM: Info : GET Connected = True
050641 2016-04-12 18:39:27.095: ASCOM: Info : GET Connected = True
050642 2016-04-12 18:39:27.109: ASCOM: Info : GET Connected = True
050643 2016-04-12 18:39:27.123: ASCOM: Info : GET Connected = True
050644 2016-04-12 18:39:27.134: ASCOM: Info : GET Connected = True
050645 2016-04-12 18:39:27.145: Driver: Info : CommandString TX=':pS#'
050646 2016-04-12 18:39:27.177: Driver: Info : CommandString: APCC response: ':APCC,5164,pS#', Response='West#'
050647 2016-04-12 18:39:27.188: Counterweight: Info : Counterweight Down
050648 2016-04-12 18:39:27.348: Driver: Info : CommandString TX=':GD#'
050649 2016-04-12 18:39:27.379: Driver: Info : CommandString: APCC response: ':APCC,5165,GD#', Response='+0000:00#'
050650 2016-04-12 18:39:27.390: ASCOM: Info : GET Connected = True
050651 2016-04-12 18:39:27.402: ASCOM: Info : GET Connected = True
050652 2016-04-12 18:39:27.413: ASCOM: Info : GET Connected = True
050653 2016-04-12 18:39:27.424: ASCOM: Info : GET Connected = True
050654 2016-04-12 18:39:27.435: ASCOM: Info : GET Connected = True
050655 2016-04-12 18:39:27.447: ASCOM: Info : GET Connected = True
050656 2016-04-12 18:39:27.549: Driver: Info : CommandString TX=':GS#'
050657 2016-04-12 18:39:27.591: Driver: Info : CommandString: APCC response: ':APCC,5166,GS#', Response='07:01:22.0#'
050658 2016-04-12 18:39:27.691: ASCOM: Info : GET Connected = True
050659 2016-04-12 18:39:27.702: ASCOM: Info : GET Connected = True
050660 2016-04-12 18:39:27.713: ASCOM: Info : GET Tracking = True
050661 2016-04-12 18:39:27.724: ASCOM: Info : GET Connected = True
050662 2016-04-12 18:39:27.735: ASCOM: Info : GET Slewing = False
050663 2016-04-12 18:39:27.766: Driver: Info : CommandString TX=':GM#'
050664 2016-04-12 18:39:27.906: Driver: Info : CommandString: APCC response: ':APCC,5167,GM#', Response='00:00:00.0#'
050665 2016-04-12 18:39:27.918: Driver: Info : CommandString TX=':GL#'
050666 2016-04-12 18:39:27.968: Driver: Info : CommandString: APCC response: ':APCC,5168,GL#', Response='18:39:27.0#'
050667 2016-04-12 18:39:27.980: ASCOM: Info : GET Connected = True
050668 2016-04-12 18:39:27.991: ASCOM: Info : GET RightAscension = 9.32452777777778
050669 2016-04-12 18:39:28.002: ASCOM: Info : GET Declination = 0
050670 2016-04-12 18:39:28.013: ASCOM: Info : GET Connected = True
050671 2016-04-12 18:39:28.024: ASCOM: Info : GET Connected = True
050672 2016-04-12 18:39:28.036: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050673 2016-04-12 18:39:28.048: ASCOM: Info : GET Connected = True
050674 2016-04-12 18:39:28.060: ASCOM: Info : GET Connected = True
050675 2016-04-12 18:39:28.071: ASCOM: Info : GET Connected = True
050676 2016-04-12 18:39:28.082: ASCOM: Info : GET Connected = True
050677 2016-04-12 18:39:28.093: ASCOM: Info : GET Connected = True
050678 2016-04-12 18:39:28.103: ASCOM: Info : GET Connected = True
050679 2016-04-12 18:39:28.129: Driver: Info : CommandString TX=':GOS#'
050680 2016-04-12 18:39:28.159: Driver: Info : CommandString: APCC response: ':APCC,5169,GOS#', Response='129000210O000#'
050681 2016-04-12 18:39:28.316: ASCOM: Info : GET Connected = True
050682 2016-04-12 18:39:28.327: ASCOM: Info : GET Connected = True
050683 2016-04-12 18:39:28.338: ASCOM: Info : GET Connected = True
050684 2016-04-12 18:39:28.349: ASCOM: Info : GET Connected = True
050685 2016-04-12 18:39:28.360: ASCOM: Info : GET Connected = True
050686 2016-04-12 18:39:28.371: ASCOM: Info : GET Connected = True
050687 2016-04-12 18:39:28.472: Driver: Info : CommandString TX=':GR#'
050688 2016-04-12 18:39:28.504: Driver: Info : CommandString: APCC response: ':APCC,5170,GR#', Response='09:19:28.3#'
050689 2016-04-12 18:39:28.627: ASCOM: Info : GET Connected = True
050690 2016-04-12 18:39:28.640: ASCOM: Info : GET Connected = True
050691 2016-04-12 18:39:28.651: ASCOM: Info : GET Connected = True
050692 2016-04-12 18:39:28.662: Driver: Info : CommandString TX=':GD#'
050693 2016-04-12 18:39:28.879: Driver: Info : CommandString: APCC response: ':APCC,5171,GD#', Response='+0000:00#'
050694 2016-04-12 18:39:28.892: ASCOM: Info : GET Slewing = False
050695 2016-04-12 18:39:28.923: ASCOM: Info : GET Connected = True
050696 2016-04-12 18:39:28.934: ASCOM: Info : GET Connected = True
050697 2016-04-12 18:39:28.944: ASCOM: Info : GET Connected = True
050698 2016-04-12 18:39:28.957: ASCOM: Info : GET Connected = True
050699 2016-04-12 18:39:28.968: ASCOM: Info : GET Connected = True
050700 2016-04-12 18:39:28.979: ASCOM: Info : GET Tracking = True
050701 2016-04-12 18:39:28.990: ASCOM: Info : GET Connected = True
050702 2016-04-12 18:39:29.001: ASCOM: Info : GET Connected = True
050703 2016-04-12 18:39:29.012: ASCOM: Info : GET RightAscension = 9.32452777777778
050704 2016-04-12 18:39:29.023: ASCOM: Info : GET Declination = 0
050705 2016-04-12 18:39:29.035: ASCOM: Info : GET Connected = True
050706 2016-04-12 18:39:29.046: ASCOM: Info : GET Connected = True
050707 2016-04-12 18:39:29.057: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050708 2016-04-12 18:39:29.118: ASCOM: Info : SET Connected = False
Regards,
-Ray Gralak
Last edit: Ray Gralak 2016-04-16
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Hi Guys,
First I want to thank you for a wonderful piece of software! It is a tremendous resource for astrophotograhers!
I'm using AstroTortilla with BackYardEOS on an Astro-Physics Mach1 mount on a Windows 10 laptop with no problems with the Astro-Physics v2 ASCOM driver.
Recently I started using the Astro-Physics Command Center (APCC) which allows things such as horizon and meridian limits.
With APCC running, AstroTortilla does not work anymore, slowing down tremendously and stopping completely.
I corresponded with the developer of APCC, Ray Gralak, to take a look at this and here are his replies:
Would there be any way to get AstroTortilla to poll less frequently or use a background thread to poll the driver?
Thanks again for a great piece of software!
Jerry Lodriguss
www.astropix.com
Last edit: Jerry Lodriguss 2016-04-13
Hi,
There should be a setting to increment the polling cache duration for badly behaving mount drivers. AT typically polls about once every few seconds to update the UI values, don't know why it should happen more frequently on your setup.
The typical root cause in those cases is a non-compliant ASCOM device driver, which passes all queries directly to the hardware. That behavior is explicitly listed as bad behavior in the ASCOM specs, which AT adheres to.
--Antti
Hi Antti,
Thank you for your response.
I am not knowledgeable enough about programing to really know how to even understand this problem, let alone fix it.
I will pass your comments along to Ray Gralak and see what he says.
Thanks again,
Jerry
Last edit: Jerry Lodriguss 2016-04-16
Hi Antti,
I forgot to mention that the AP ASCOM driver is fully ASCOM compliant, here is the ASCOM conformance check file:
http://www.gralak.com/apdriver/AstroPhysicsV2.Telescope.Validation_5.08.07.txt
Jerry
Hi Antti,
This is Ray Gralak, the author of the Astro-Physics V2 ASCOM driver and also APCC. Although I understand your response above I have analyzed the driver log files and I don't think it's the driver's fault that AstroTortilla user interface sometimes responds slowly when connected. Note that APCC and the driver are not acting slowly, only AstroTortilla (AT), and here is what I think is happening based on the logs.
First, AT is the only application I've ever heard of that slows down when using the AP driver+APCC.
Second, as evidence of the origin of possible "bad behavior" at the end of this post is a clip of the AP V2 driver log I captured. The only application polling the ASCOM "Connected" property was AT as it was the only application connected to the driver. AT is trying to poll the ASCOM "Connected" property every 10-20 milliseconds. The offending calls in the log clip are those with "GET Connected = True". There are time stamps to the nearest millisecond on each line so you can see the timing. What is unknown is the overhead of COM interop from AT's point of view, it could be longer than the timing intervals suggest. You would have to put timers in AT to measure that.
Since almost all ASCOM drivers are Single Apartment threaded, including the AP V2 driver, there is only one thread supporting all calls and background actions. The AP V2 driver runs background timers to poll and cache important state information. During that polling if an ASCOM client communicates with it then the client might have to wait in line because of the way COM interop serializes requests.
So here is what I think is the problem... if AT is accessing the driver on AT's user interface thread instead of a background thread then while waiting for a response from the driver AT's user interface might appear to lock up until the response is returned. If this is happening often enough, then to the user this might make AT appear to act slow because of the tiny pauses.
If AT could use a background thread then AT's UI would not be blocked while it waits and thus user interface actions would never appear to be slow. Or, if AT could reduce the poll rate of the "Connected" property then AT's UI would also not appear to be slow under those same conditions. I think AT should only need to poll "Connected" once, or at most twice, a second.
Here is the log clip:
050628 2016-04-12 18:39:26.552: ASCOM: Info : GET Connected = True
050629 2016-04-12 18:39:26.563: ASCOM: Info : GET Connected = True
050630 2016-04-12 18:39:26.574: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050631 2016-04-12 18:39:26.753: Driver: Info : CommandString TX=':GR#'
050632 2016-04-12 18:39:26.764: ASCOM: Info : GET Connected = True
050633 2016-04-12 18:39:26.976: Driver: Info : CommandString: APCC response: ':APCC,5163,GR#', Response='09:19:28.3#'
050634 2016-04-12 18:39:26.989: ASCOM: Info : GET Connected = True
050635 2016-04-12 18:39:27.001: ASCOM: Info : GET Connected = True
050636 2016-04-12 18:39:27.012: ASCOM: Info : GET Connected = True
050637 2016-04-12 18:39:27.023: ASCOM: Info : GET Connected = True
050638 2016-04-12 18:39:27.034: ASCOM: Info : GET Connected = True
050639 2016-04-12 18:39:27.066: ASCOM: Info : GET Connected = True
050640 2016-04-12 18:39:27.079: ASCOM: Info : GET Connected = True
050641 2016-04-12 18:39:27.095: ASCOM: Info : GET Connected = True
050642 2016-04-12 18:39:27.109: ASCOM: Info : GET Connected = True
050643 2016-04-12 18:39:27.123: ASCOM: Info : GET Connected = True
050644 2016-04-12 18:39:27.134: ASCOM: Info : GET Connected = True
050645 2016-04-12 18:39:27.145: Driver: Info : CommandString TX=':pS#'
050646 2016-04-12 18:39:27.177: Driver: Info : CommandString: APCC response: ':APCC,5164,pS#', Response='West#'
050647 2016-04-12 18:39:27.188: Counterweight: Info : Counterweight Down
050648 2016-04-12 18:39:27.348: Driver: Info : CommandString TX=':GD#'
050649 2016-04-12 18:39:27.379: Driver: Info : CommandString: APCC response: ':APCC,5165,GD#', Response='+0000:00#'
050650 2016-04-12 18:39:27.390: ASCOM: Info : GET Connected = True
050651 2016-04-12 18:39:27.402: ASCOM: Info : GET Connected = True
050652 2016-04-12 18:39:27.413: ASCOM: Info : GET Connected = True
050653 2016-04-12 18:39:27.424: ASCOM: Info : GET Connected = True
050654 2016-04-12 18:39:27.435: ASCOM: Info : GET Connected = True
050655 2016-04-12 18:39:27.447: ASCOM: Info : GET Connected = True
050656 2016-04-12 18:39:27.549: Driver: Info : CommandString TX=':GS#'
050657 2016-04-12 18:39:27.591: Driver: Info : CommandString: APCC response: ':APCC,5166,GS#', Response='07:01:22.0#'
050658 2016-04-12 18:39:27.691: ASCOM: Info : GET Connected = True
050659 2016-04-12 18:39:27.702: ASCOM: Info : GET Connected = True
050660 2016-04-12 18:39:27.713: ASCOM: Info : GET Tracking = True
050661 2016-04-12 18:39:27.724: ASCOM: Info : GET Connected = True
050662 2016-04-12 18:39:27.735: ASCOM: Info : GET Slewing = False
050663 2016-04-12 18:39:27.766: Driver: Info : CommandString TX=':GM#'
050664 2016-04-12 18:39:27.906: Driver: Info : CommandString: APCC response: ':APCC,5167,GM#', Response='00:00:00.0#'
050665 2016-04-12 18:39:27.918: Driver: Info : CommandString TX=':GL#'
050666 2016-04-12 18:39:27.968: Driver: Info : CommandString: APCC response: ':APCC,5168,GL#', Response='18:39:27.0#'
050667 2016-04-12 18:39:27.980: ASCOM: Info : GET Connected = True
050668 2016-04-12 18:39:27.991: ASCOM: Info : GET RightAscension = 9.32452777777778
050669 2016-04-12 18:39:28.002: ASCOM: Info : GET Declination = 0
050670 2016-04-12 18:39:28.013: ASCOM: Info : GET Connected = True
050671 2016-04-12 18:39:28.024: ASCOM: Info : GET Connected = True
050672 2016-04-12 18:39:28.036: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050673 2016-04-12 18:39:28.048: ASCOM: Info : GET Connected = True
050674 2016-04-12 18:39:28.060: ASCOM: Info : GET Connected = True
050675 2016-04-12 18:39:28.071: ASCOM: Info : GET Connected = True
050676 2016-04-12 18:39:28.082: ASCOM: Info : GET Connected = True
050677 2016-04-12 18:39:28.093: ASCOM: Info : GET Connected = True
050678 2016-04-12 18:39:28.103: ASCOM: Info : GET Connected = True
050679 2016-04-12 18:39:28.129: Driver: Info : CommandString TX=':GOS#'
050680 2016-04-12 18:39:28.159: Driver: Info : CommandString: APCC response: ':APCC,5169,GOS#', Response='129000210O000#'
050681 2016-04-12 18:39:28.316: ASCOM: Info : GET Connected = True
050682 2016-04-12 18:39:28.327: ASCOM: Info : GET Connected = True
050683 2016-04-12 18:39:28.338: ASCOM: Info : GET Connected = True
050684 2016-04-12 18:39:28.349: ASCOM: Info : GET Connected = True
050685 2016-04-12 18:39:28.360: ASCOM: Info : GET Connected = True
050686 2016-04-12 18:39:28.371: ASCOM: Info : GET Connected = True
050687 2016-04-12 18:39:28.472: Driver: Info : CommandString TX=':GR#'
050688 2016-04-12 18:39:28.504: Driver: Info : CommandString: APCC response: ':APCC,5170,GR#', Response='09:19:28.3#'
050689 2016-04-12 18:39:28.627: ASCOM: Info : GET Connected = True
050690 2016-04-12 18:39:28.640: ASCOM: Info : GET Connected = True
050691 2016-04-12 18:39:28.651: ASCOM: Info : GET Connected = True
050692 2016-04-12 18:39:28.662: Driver: Info : CommandString TX=':GD#'
050693 2016-04-12 18:39:28.879: Driver: Info : CommandString: APCC response: ':APCC,5171,GD#', Response='+0000:00#'
050694 2016-04-12 18:39:28.892: ASCOM: Info : GET Slewing = False
050695 2016-04-12 18:39:28.923: ASCOM: Info : GET Connected = True
050696 2016-04-12 18:39:28.934: ASCOM: Info : GET Connected = True
050697 2016-04-12 18:39:28.944: ASCOM: Info : GET Connected = True
050698 2016-04-12 18:39:28.957: ASCOM: Info : GET Connected = True
050699 2016-04-12 18:39:28.968: ASCOM: Info : GET Connected = True
050700 2016-04-12 18:39:28.979: ASCOM: Info : GET Tracking = True
050701 2016-04-12 18:39:28.990: ASCOM: Info : GET Connected = True
050702 2016-04-12 18:39:29.001: ASCOM: Info : GET Connected = True
050703 2016-04-12 18:39:29.012: ASCOM: Info : GET RightAscension = 9.32452777777778
050704 2016-04-12 18:39:29.023: ASCOM: Info : GET Declination = 0
050705 2016-04-12 18:39:29.035: ASCOM: Info : GET Connected = True
050706 2016-04-12 18:39:29.046: ASCOM: Info : GET Connected = True
050707 2016-04-12 18:39:29.057: ASCOM: Exception : GET TargetRightAscension (property not set) = 0
050708 2016-04-12 18:39:29.118: ASCOM: Info : SET Connected = False
Regards,
-Ray Gralak
Last edit: Ray Gralak 2016-04-16