Sequence 600s countdown took 2 hours (Dispatcher overload warning?)

[lowenthalm]

The following issue was encountered using version 4.1.11003.0-64bit under Windows 10 running under Parallels on an Intel MacBook Pro.

I started a sequence at 01:39:58 to capture darks at two temps with the following series of operations:

1) Capture darks for 30s exposures @ bin 1 and bin 2 at -10C
2) warmed up the camera from -10C to -5C, then wait 10 minutes to be sure its stable at the new temperature
3) Capture darks for 30s exposures @ bin 1 and bin 2 at -5C
4) Shutdown the cooler, wait 8 minutes and then close the camera

During step 2 at 02:48:13, the sequence started a 600s countdown to allow the cooler time to further stabilize after the temperature change. This sequence step took over half an hour to run, ending at 03:21:06! During running this countdown, the following warning showed up, which sounds relevant:

Info 03:17:33.036889 #32 =='.NET ThreadPool Worker' (New Thread)
Warning 03:17:33.040138 #32 Possible dispatcher overload. Background priority not run for 20.6s since 10:17:12 AM. Dispatcher queue length is 10, currently 1 in progress. in async Task SharpCap.UISwitcher+DispatcherWatchDog.MonitorDispatcher()

During 4, after shutting down the camera, the sequence started another 480s countdown to allow the cooler to come back to ambient before closing the camera. This countdown started at 04:23:36 and ended at 06:18:46!! At 04:41:57 a similar warning message to the above appeared.

The camera was in live view mode at this time. I ran some more tests when I got up in the morning when I saw this strange behavior in the sequence log. You can see the testing a 600s countdown starting at 08:14:12 in the log, with live view still on, and ended at 08:29:28. Not as bad - only 5 minutes too long. There were no dispatcher overload warnings. I reran this countdown test (it seems after then end of the attached log) with live view turned off, and it took exactly 10 minutes to run, as one would expect.

It looks like there is still a lot of debugging code present, so that is probably slowing things down during live-view capture. However, almost 2 hours to run a 480 second count down, with some dispatcher overload warnings looks suspect, so I thought I better report it.

I was running some python script testing earlier in the evening. I was just debugging some scripts to get and then change some camera control values and live stack conntrol values. Nothing fancy with modifying the interface or anything like that. I don't think I broke anything here...hopefully.

[admin]

Hi,

the dispatcher overload log entries imply that SharpCap hasn't processed user interface updates fully for the given period of time. It's possible that this could be caused by sending a command to an ASCOM device that is taking a long time to reply, or certain scripting actions could lock up the UI for a while. It seems that things recover fairly quickly in most of the cases, so I don't think this is the problem causing a very long delay.

Looking through the log, I can't see anything related to cooling in the sequence you ran, so I presume that must be in your python code. It would be useful to have a look at that. I did notice these entries in the log

Code: Select all

Warning 23:39:40.746540 #33 Error from python scripting : Traceback (most recent call last):
  File "<string>", line 162, in <module>
NameError: name 'Raise' is not defined

Maybe you are using 'raise' with an uppercase R somewhere in your code which might affect what it is doing?

cheers,

Robin

[lowenthalm]

I was testing Python code fragments and had a cap in the wrong place. I need to use a different text editor. I have just been getting and setting control settings in the python code. Nothing fancier, as its all I need for what I want to do right now.

I have been avoiding complicated SC interface modifications, periodic tasks, etc as that can cause problems if I don't know exactly what I am doing. I am still learning/figuring out the SC python API, so I most definitely don't know exactly what I am doing! As 4.1 is still in late beta, I also don't want to introduce instabilities that weren't there until I started poking at it too much with Python.

As for ASCOM issues you suggest as a possible issue, the "since 10:17:12 AM" is confusing me. The log starts when I opened SharpCap at 19:34:14. The error appears at around 03:17 (AM). Sharpcap wasn't running at 10:17:12 AM. However, it was running at 10:17:12 PM. Due to this, I am not sure where to go looking in the log to see if I can spot which ASCOM device might be the culprit.

[admin]

Hi,

some of the timings in the log will be UTC (SharpCap internally uses UTC a lot, since it avoids issues with 'something needs to run every 30 seconds' having problems if the clocks change from daylight saving to normal time or back again). I suspect that the 10:17:02 is one of those UTC timings.

cheers,

Robin