Foc1 Auto-Focusing was conducting a Focus Profile for a star field around Target 6/36 (UGC 4719) at 23:31 when a single rogue point led to 'best-focus' position being incorrectly determined at 1452, and as a consequence an incorrect focus offset being set for the target.   Images from the target were sub-optimally focused, but were still usuable.   Problem was spotted at 00:01 during remote monitoring and an interventation made to undo the bad Focus Offset.   It is unclear if standard focusing for the next target with a brighter enough focus star in starfield (S Cyg / Profile 6) would or wouldn't have refound the correct focus position if the manual interventation hadn't been made.  

The rogue point at 1452 has a FWHM (2.47") and a HFD (4.1") which were both lower (notionally better focused) than points associated with actual best focus at c.1900-1950).   The point also displaces the 'best fit quadratic curve'  away from actual best focus to a position that is around midway between actual best focus and the rogue point position.  The Foc1 Autofocusing has selected the Rogue Point as 'best focus' in preference to the 'best focus' from quadratic curve fit.

Examination of focus frames (see below) shows that Frame at 1452 contains a small (but sharp/bright ) artefact to right of focus star, most-likely from a cosmic ray hit, that has misled the FWHM measurements for the frame.  

The Autofocusing routine selects the position of highest FWHM on the assumption if there is a large difference in position between best fit curve and the highest FWHM point, then it is most-likely that the best fit curve has been displaced by some other anomalous point (expected to be lower than peak FWHM close to best focus).   This assumption clearly doesn't work in this particular case, where it would probably have been best to recognise that the profile is compromised and to not update the focus offset but leave it unchanged. 

Focus Profile 5 Rogue point at 1452

Focus Frames from Profile 5 compared Rogue point Frame at 1452 (left),  Frame near best focus at 1972 (right) It can be seen Rogue Point Frame has a small (but sharp/bright ) artefact, most--likely from a cosmic ray hit, that has misled the FWHM measurements for the frame.

Focus Profile 6

Best Focus Chart for Session S806 for Focus Field 21 The erronous 'best focus' position associated with Profile 5 can clearly be seen.

Windows 10 on the Development Computer finally enforced an update of the Windows 10 Pro operating system today from 1909 (installed 2019-08-05) to 2004 (installed 2020-09-05).    After restarting the computer the new version was installed and configured.  

CCDSoft5
Not unexpectedly installation of the new Windows 10 version 'broke' CCDSoft5' program.   Attempting to start CCDSoft produced a series of error messages reporting that several  .DLL files couldn't be found (including APOGEE32.dll, CFWAPI.dll, DSS_DLL.dll, ipl.dll, TiffPli.dll,  RelayAPI.dll,  TTY32.dll, ASTROM.dll,  eigenval.dll, EIGENVAL2.dll, SE.dll, PVAPI.dll). 

The same thing happened previously on Development Computer when it was upgraded from Windows 10 1803 to 1903 (see Windows 10 upgrade (1903) & CCDSoft DLLs (2019-08-03)  ) an old AllSky/Weather Computer following the  April 2018 update to Windows 10  (see AllSky Laptop - CCDSoft, TheSky & CCDApp2_AllSky Installation (2018-06-11) ) and an old Observatory Computer in 2016 when an attempt was made to update Windows 7 to Windows 10.    The referenced files are missing from 'C:\Program Files (x86)\Common Files\System'

As in 2018 the solution was to copy the required DLL files into the Common Files\System folder from the Common\System folder of another computer on the home network with CCDSoft5 is installed.  This step was somewhat simplier this time as the collection of required .DLL files was already set aside in a standby folder for exactly this circumstance. 

TeleAPI
Notes from 2019 when Windows 10 was upgraded in 1903 (see Windows 10 upgrade (1903) & CCDSoft DLLs (2019-08-03) ) indicated a problem with TeleApi following Windows 10 update.  TheSky6 was therefore examined to see if TeleApi was functioning correctly and finding that it wasn't,  the TeleApi setup (TeleAPI(5.0.4)Setup.exe) was rerun which eventually fixed the problem.

Regsvr32
It was conjectured that registering the referenced .dll files using "regsvr32.exe" might possibly prevent a future reoccurance of the problem.
e.g.  Using Adminstrator Command Prompt :
%systemroot%\System32\regsvr32.exe  "C:\Program Files (x86)\Common Files\System\eigenval.dll" (64 bit version), or
%systemroot%\SysWoW64\regsvr32.exe "C:\Program Files (x86)\Common Files\System\eigenval.dll"  (32 bit version)

However when run the RegSvr32 process produces an error message saying that the ".dll file was loaded but the entry point DllRregisterServer was not found. Make sure the <path to .dll file> is a valid DLL or OCX file and try again"

Apparently just because a file has a .dll extension doesn't mean it is registerable.   So RegSvr32 doesn't help us.  

The solution is therefore to simply re-copy the .dll files into the ..\Common Files\System folder following the update (making sure one has the required DLLs to hand).   This is far quicker than the alternate solution that would involve reinstalling CCDSoft (which is complicated because of multiple version steps that seem to have to be gone through between the original CD version and the latest version).

An investigation was carried out today (2020-09-07) as a follow-up to a sequence of Dome Problems during a previous session (S505, 2020-09-04)

Issue:
Problem Closing Dome (00:53). Dome appears non-responsive or stuck. . Session Shutdown stuck

Description
Sky conditions deteriorated at 00:51 (AllSky StarCount dropped to 17, which was below the threshold of 20 stars being used), and Obs.Manager called a Soft Suspend. Following completion of current target (DY Per) the session suspended at 00:53 and 'Closing Dome' was reported.    However there was no corresponding message line or event to report that dome closure had been completed.
AstroGuard observed that Dome was closing at 00:53 but noted that shutter had taken > 68s to close.  

At 01:53 sky conditions became critical and AstroGuard checked the dome and found the dome to be closing.  At 03:17 sky conditions again became critical and AstroGuard again checked the dome and found the dome to be closing.  At 04:28 conditions improved and Obs.Manager attempted to resume the session and open the Dome, but found that dome opening hadn't finished afer 90s and note there may be a 'mechanical or electrical issue' and commanded a Dome Closure as a precaution.  A similar attempt to resume the session and open the dome was made at 04:49 but the again the dome was found to not have opened after 90s.  Session entered Closing State at 04:57 but progress became seemingly stuck in a loop associated with 'Close Dome'.

Observatory Status was checked via WebSite at 05:15 and the finding the dome to be slewing and closing when it should have been parked and closed, and the Close Down observatory seemingly stalled, the Observatory was visited to check precise situation.  Dome was found to be closed , but pointing towards WNW (Az. 280 degs). Scope was pointing at to ENE sky at 70 deg inclination with Tracking Off.  Telescope was parked via Device Hub at 05:31 Dome Service restarted in AstroMain at 05:33.  Dome was parked via AstroGuard at 05:34.  

Analysis
Looking back at the set of saved ObsPics shows the Dome going  to Az. 280 at 00:26 for Target 8/32 (GCVS AM Her) but not moving when scope went on to Target 9/32 (Z And) at 00:34 or to Target 10/32 (DY Per) at 00:43. Discrepency between Scope and Dome Azimuths were reported following slew to both targets.

A similar issue has been seen before on session Sxxxx (2020-0x -xx), its unclear if this is a dome/dome driver issue or an issue related to use of DeviceHub (instead of POTH.Hub).    

Examining the Dome's ASCOM Trace Log shows the regular sequence of requests every 5s ( 'Connected Get' ,  'ShutterStatus' etc) stops being logged  after the request at 00:27:07 which corresponds with the time that ObsPic show the Dome not responding.   Volatile message line continue every 1s suggesting that Pulsar Dome Driver is still getting information from the Dome Drive Unit.  The Trace Log shows a Close Shutter request at 00:53 and the shutter moves to state 3 (closing) at 00:53:08, and to state 1 (closed) at 00:53:50 (i.e. a normal closing time of 42s)
At 04:28:45 there is an Open Shutter request and the shutter opens between  04:28:46 and 04:29:26 (opening time 50s)
Close Shutter / Open Shutter requests at 04:30:15, 04:49:47,  04:51:17 are similarly met. Finally there is a Close Shutter request at 05:34:26 (shutter already closed) and a Park Request at 05:34:26, which is completed at 05:35:38 (Az 90.0 degs).

Obs.Manager Code Review (SessionState = Closing)
   Closing Stage 0
   If  Dome.ShutterIsClosed = False  Then
       Dome.CloseShutter2() routine
   End If
   ClosingStageNo = 1

   Closing Stage 1
   If Dome.ShutterIsClosed() Or (FinalCloseShutterAttempts = 3 And SecondsSince(TimeCloseShutterRequested) > 120) Then
      ClosingStageNo = 2
  ElseIf Dome.ShutterIsOpen() And SecondsSince(TimeCloseShutterRequested) > 120 Then
     ClosingStageNo = 0
  End If

 It can be seen that if ShutterStatus is stuck on ShutterState.Closing as was in this case (and is thus unable to reach the Closed State), further progress in Closing Down the Session can not be made (the operation is 'stuck' in ClosingStage1) . Obs.Manager is still running and monitoring other conditions, it just cannot move onto to Park Dome (which). Park Scope, Close Down Camera etc, finisihing with HouseKeeping and the end of the session.

 Beside relying entirely on the DeviceHub, it is possible to monitor / read the Pulsar Dome Ascom log to identify / resolve discrepencies between what the Dome is saying and what Device Hub is saying.

Conclusion
It seems that DeviceHub is passing client requests to Open/Shut the Dome through to the Dome Driver, but has stopped getting updates from Pulsar Dome Driver.  It would appear that the relevant thread in DeviceHub for doing this has 'frozen' or otherwise stopped working or can't return new results. The DeviceHub thread that monitors the Telescope position and automatically moves the Slaved Dome when Scope moves also appears to have stopped working.

(Whilst 5s is the cycle time for Obs.Manager, 2s is cycle time for Observatory Monitoring,  AstroGuard also uses a 5s cycle time but likely a different phase to Obs.Manager , the 5s frequency of Dome reads is dependant on DeviceHub's own cycle time when the dome is stationary. When Slewing the DeviceHub's read cycle time appears to increase to 1s).

The fact that both AstroMain and AstroGuard clients aren't getting correct information about the status of the Dome from 00:27 onwards would indicate a problem in the DeviceHub (the Server) rather than a problem coincidentally happening in both Clients at the same time. 
(Its impossible to rule out a problem in Pulsar Dome Driver, but there are no indications of this from examing the ASCOM trace log and doesn't seem to happen when running POTH.Hub).

Work Required
Problem needs to be spotted by the Obs.Manager and an appropriate Alert generated for first new occurance of the problem. The dome should probably be disconnected by both AstroMain and AstroGuard before reconnecting the dome and reappraising the situation. If this doesn't resolve the problem the Telescope might also need to be disconnected (by AstroMain, AstroGuard & PHD2) and Device Hub closed / restarted.

Problem should be reported to DeviceHub's author (Rick).

Close Session Routine needs to prevent itself getting stuck in an endless cycle waiting for Dome to Close and have a timeout facility to allow Dome Shutdown to conclude, with appropriate error reporting & alerts on Dome Closure & Dome Parking.

An investigation was carried out today (2020-09-07) as a follow-up to a sequence of Dome Problems during a recent session (S805, 2020-09-04)

Issue:
Telescope slew to Target 6/36 appears to cross North Celestrial Pole.  

Description
The session's scope slewing chart shows a scope track going to Target 6/36 (UGC 4719) that seems to pass across the North Celestrial Pole. This is a slew that is impossible for the fork mounted LX200 main scope;  the actual slew would have seen a slew path that rotates around the celestrial pole axis (like the slew away from UGC 4719) that maintains a Declination outside of high-Dec no-go region where the CCD Camera would have clashed into the fork base.

Reviewing the log file shows that only the first 1 or 2 points along the scope path (ie for first 1s) have been captured, the rest of the scope path hasn't been recorded. Without the rest of the path, the Dome/Scope Slewing Chart has more or less drawn a straight line between starting coordinates (Az 164.7) and ending coordinates (Az 3.8) and this passes across the north celestrial pole. The prior slew and the next slews produced 15-27 points along the slew path (i.e. a normal number) .  Code needs to be investigated to see what could have caused to record only 2 points or to otherwise exit the slew path monitoring routine early.

Code Review
Looking at Scope.SlewTheSkyScope() routine,  ScopePath points are only generated when the angular change between successive position reads is > 0.1 arc min.  Given the large slew (176 arc degs) and assuming that DeviceHub was returning correct and timely positional values from the Scope, extra Slew Path points should have been generated unless bScopeCompleted was pre-maturely set to True.  

bScopeCompleted can only be set to True under two conditions when DeviceHub is being used

a)  when bScopeSlewStarted=True and Scope.Slewing = false
b) when bScopeSlewStarted=false and Scope.Slewing = false and Telescope.IsSlewComplete = 1

Now b) can be ruled out as the logfile doesn't contain the unique message "Setting bScopeCompleted whilst bScopeSlewStarted is still False"

Scope.Slewing doesn't access objScope.Slewing unless there is >1s since the last access.  So whilst is could be imagined that Slewing could have started (True) but Scope.Slewing could still be showing a pre-slewing value (False) it can be seen that bScopeSlewStarted is only set to True if Scope.Slewing = True.   The next Scope.Slewing call should therefore also give True if it is within 1s or give True because objScope.Slewing is true because it still has a long way to reach the target.  So condition a) shouldn't have been met until the Target was finally reached.

The Report File and Slew Table show that Scope slewing time was 74s.  Whilst Scope.LastSlewSeconds is set when bScopeCompleted is set to True, it is overwritten later after both Dome&Scope have finished slewing when it is set to number of seconds between TimeLastMovement detected (AngularChange > 0.1 arc min) and StartTime.  

A reduced list of scope paths could conceivably resut if there is an exception within the routines, but the absence of any logged exception message and the timings (75s between start and end messages) don't support such an explanation.  

Conclusion
The only explanation left is that for the duration of the slew DeviceHub stopped returning up to date telescope Ra, Dec coordinates.  With a 'frozen position' there would be no angular change between successive reads and therefore no ScopePath points would have been generated.

Fix/Workaround
The problem is not critical and doesn't effect the slewing to target, but it does produce a cosmetically unappealing and distracting graph result and reduces the information available for investigation/diagnosis should some incident occur (e.g. camera hits fork) and one needs to understand what had happened.

Workarounds would be to revert back to POTH.Hub, but this Hub is being retracted in ASCOM in favour of the new DeviceHub replacement.

Problem should be reported to DeviceHub's author (Rick) for his comment.

In meantime it would be useful to modifiy code and record exact instances where scope coordinates from DeviceHub have remained static during a telescope slew for longer than 2 seconds. This would at least help narrow down the problem.  This was done in AstroMain 3.28.4, but still having some issues in S810 (2020-09-17) with log showing telescope position appearing to be 'static' for up to 3s at a time during the slew.

Problem eventually resolved by installing DeviceHub 6.4.1.11 and setting the telescope Fast Poll Rate to 0.5s.
Fixed 2020-09-18 (DeviceHub 6.4.1.11)

An analysis was carried out to compile the typical time taken to complete Foc1/Foc2 Autofocusing including precursive wide focus search.  This is data is needed to ensure that Obs.Manager opens the observatory at a time that is earlier enough  for autofocusing task to be completed before the beginning of the time slot of the first target.

S806

Session Equilibration                   2020-09-05 22:46  (Local)        Actual
  Now                         Info      2020-09-05 22:46  (  -8 mins )   22:46:27   ( 30s late)
  Expected Shutter Opening    Info      2020-09-05 22:46  (  -8 mins )   22:46:27
  Expected Equilbrat'n Start  Info      2020-09-05 22:47  (  -7 mins )   22:47:13   ( 15s late)
  Expected Run Start          Info      2020-09-05 22:47  (  -7 mins )   22:47:38   ( 30s late)
  Expected Near-Zenith Foc1   Info      2020-09-05 22:48  (  -6 mins )   22:48:47   (~ 1 min late)  (8 min instead of 3)
  Expected Near-Zenith Foc2   Info      2020-09-05 22:51  (  -3 mins )   22:56:35   (~ 5 min late)  (5 min instead of 3)
  Expected Queue Start        Info      2020-09-05 22:54  (   0 mins )  
  Plan Queue Start            Info      2020-09-05 22:54  ( On Track )   23:01:13   {~ 7 min late)

S804

Session Equilibration                   2020-09-03 21:18  (Local)        Actual
  Now                         Info      2020-09-03 21:18  ( -11 mins )
  Expected Shutter Opening    Info      2020-09-03 21:18  ( -11 mins )   21:18:39    (40s late)
  Expected Equilbrat'n Start  Info      2020-09-03 21:19  ( -10 mins )   21:19:25
  Expected Run Start          Info      2020-09-03 21:19  ( -10 mins )   21:23:05    ( 4 min late)
  Expected Near-Zenith Foc1   Info      2020-09-03 21:20  (  -9 mins )   21:23:51    ( 2.5 min late) (8 min instead of 3)
  Expected Near-Zenith Foc2   Info      2020-09-03 21:23  (  -6 mins )   21:31:50    ( 10 min late)  (5 min instead of 3)
  Expected Queue Start        Info      2020-09-03 21:26  (  -3 mins )
  Plan Queue Start            Info      2020-09-03 21:30  ( On Track )   21:36:46    ( 15 min late)