LUCIFER Com 3, Night 1
UT 2009 January 10

Observers: N.Ageorges, W.Seifert, R.Gredel, M.Juette, D.Thompson (@LBT) and J. Hill in Tucson for part of night.
Telescope Operator: A.Ceranski
SW Support: N.Cushing in Tucson

Summary:

  • Collimation model from last night's data generated, implemented.
  • LUCIFER orientation on sky corrected, but untested (will do so tomorrow).
  • REL RADEC offsets appear to be incorrectly applied, see IT#1909
  • Two SW issues documented at length below.
    • One self-recovered after 3.5 minutes of log silence everywhere
    • The other appears to be GCS hanging shortly after a pause guiding request.
  • Unrecoverable cell panic at 12:55 (JHill called, J.Rousseau awakened). Lost 7 hours (IT#1947)
  • Proposed IIF.isGuiding flag logic documented for further discussion.

Guider and WFSC data moved to /Repository/AGW_Data/090110g and 090110w (DLM)

Details:

16:55 Open for twilight flats

T=-1.3, RH=24.6, Wind ~8m/s average. Pretty clear.

Implemented collimation model derived from last night's data. See attached plot. Qualitatively the same as the previous model (using the same temperature coefficients), but with shifts in the curves.
20090109.collim.jpg:
20090109.collim.jpg

Initial pointing and collimation correction
18:33:18.488 Preset: pointing corrected to IE = -19.40000, CA = 7.00000
18:37:22.580 Preset to collimate. 2220, 2147, 1540, 1095, 1030, 539, 417, 465, 365 nm on WFS
FWHM on guider is ~1.5 arcsec

Offset tests with LUCIFER

REL offsets in RADEC space appear to be applied as ABS. Called Michele. Successive offsets in DEC of the same amount resulted in no motion of the telescope. Note added to Issue Trak #1909.

offset +30 in DEC from lucifer and the current DEC in the DD reads 48:38:23.4
offset another +30 in DEC from lucifer and the current DEC in the DD now reads 48:38:53.4
but the achieved DEC did not change.

19:35:58.149 2009 StepFocus alert for left LUCIFER: Primary mirror collimation reached limit
Offset -2mm on both M1 and M2, re-sent preset. Looks OK.

Note that LUCIFER is sending a flipped sign in DETXY offsets in the X direction so that the source goes to the correct place on the detector. This is coupled to the Xflip in PCS that is incorrect because the way I had drawn the telescope focal plane coordinates had a flip in it.

DETXY offsets in ABS and REL seem to work as expected, except that ABS 0 0 appears to have not moved back to the origin. This may be a misunderstanding of the ABS 0,0,0 functionality as applied to DETXY and RADEC space.

Jan 9 20:56:28 lbtmu107 LBT_left_GCS: verifying star is inside box and stable...
This started a 3-4 step spiral onto the hotspot.

10:55 Based on measurements from 23 images over the last 2 nights, LEFTZEROPOINT was updated to -187.250. The rms of the offsets is 0.032 degrees. PCS needs to be restarted to implement this.

Fri Jan 9 23:05:03.228 2009 StepFocus alert for left LUCIFER: Primary mirror collimation reached limit
This time it got to -2.6mm. We hit the positive limit earlier tonight. This was my (dthompson) fault - I applied a 4mm offset instead of the needed 2 mm.

11:09 PCS restarted to have LEFTZEROPOINT update take effect, IE and CA from earlier correction re-sent. First two presets after that failed for lack of guide star because IE was not correctly reset.

11:22 IE = -15.0 CA=-5.0

11:22:48 PROBLEM This is an example of what was happening last night that caused us to kill and restart GCS. Can we find out what was happening between 23:22:48.808 and 23:26:17?

Overview of problem...
23:22:48.808 Preset sent on the target we were already on
23:26:17 PCS set new target logged
23:26:21 slewtotrack done,
23:27:18.866 preset complete

Details of problem from the LSS event database...
Fri Jan  9 23:22:48.808 2009  IIF IIF Preset command started for left LUCIFER mode ACTIVE from IIF
Fri Jan  9 23:22:48.853 2009  GCSL [gcs.command.stopGuiding.triggered]
What happened during this 3.5 minute interval ?

Details from the GCS syslog...

There is nothing in the GCS syslog entries between:
Jan 9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid execution time: 87 ms at 1231569528891
and
Jan 9 23:26:18 lbtmu107 LBT_left_GCS: GCSL:setGuidestarList executed

Further details from the LSS event database showing once the 4 minutes passed everything worked as expected...
Fri Jan  9 23:26:17.438 2009  PCS PCS will set new target to RA: 1.831637237946493e+00 Dec: -8.568209148985052e-02 RotMode: POSITION Angle: 0.000000000000000e+00 Wavelength: 0.0000000e+00 Side: 0
Fri Jan  9 23:26:17.469 2009  PCS PCS set new target to RA: 1.831637237946493e+00 Dec: -8.568209148985052e-02 RotMode: POSITION Angle: 0.000000000000000e+00 Wavelength: 0.0000000e+00 Side: 0
Fri Jan  9 23:26:17.511 2009  PCS PCS will start tracking target
Fri Jan  9 23:26:17.517 2009  MCS LFBG slewToTrack command received
Fri Jan  9 23:26:18.290 2009  PCS - Seconds of wait: 7.5000000e-01.
Fri Jan  9 23:26:18.364 2009  GCSL [gcs.command.setGuidestarList.triggered]
Fri Jan  9 23:26:18.427 2009  ECS Hydraulic bearing command set temperature set point completed:temp -1.0028999e+01 
Fri Jan  9 23:26:18.281 2009  MCS AZ slewToTrack command received
Fri Jan  9 23:26:18.282 2009  MCS EL slewToTrack command received
Fri Jan  9 23:26:18.286 2009  MCS LFBG slewToTrack command received
Fri Jan  9 23:26:18.287 2009  MCS LFBG Rotator:  commanded to slew to the object for which tracking polynomials are being sent. result = ''OK''
Fri Jan  9 23:26:21.105 2009  MCS LFBG slewToTrack operation is done and state machine is changing to track state.
Fri Jan  9 23:26:25.104 2009  GCSL [gcs.interface.pcs.adjustGSCoordinates.called]
Fri Jan  9 23:26:25.125 2009  PCS PCS AdjustGSCoordinates for guide star with RA 1.831510000000000e+00 and Dec -8.493539999999999e-02
Fri Jan  9 23:26:25.139 2009  PCS PCS AdjustGSCoordinates for guide star to SFP - Xi 1.573845093262957e+01 and Eta 9.265128506788646e+01
Fri Jan  9 23:26:25.163 2009  GCSL [gcs.interface.pcs.adjustGSCoordinates.returned]
Fri Jan  9 23:26:25.544 2009  GCSL [gcs.interface.agw.setProbePosition.called]
Fri Jan  9 23:26:44.306 2009  GCSL [gcs.interface.agw.setProbePosition.returned]
Fri Jan  9 23:26:46.376 2009  PSFL left PSF primary mirror adjustMirrorCollimation started for 0 seconds in the future
Fri Jan  9 23:26:46.382 2009  PSFL left PSF secondary mirror adjustMirrorCollimation started for 0 seconds in the future
Fri Jan  9 23:26:46.383 2009  PSFL left PSF tertiary mirror adjustMirrorCollimation started for 0 seconds in the future
Fri Jan  9 23:26:46.471 2009  PMCL left PMC Mirror GoToPositionAbs Command Started
Fri Jan  9 23:26:46.472 2009  OSS oss.side[0].secondary_mirror: [moveAbs] started
Fri Jan  9 23:26:46.477 2009  OSS oss.side[0].tertiary_mirror: [adjustCurrFocalStation] started
Fri Jan  9 23:26:46.534 2009  OSS oss.side[0].tertiary_mirror: [adjustCurrFocalStation] complete
Fri Jan  9 23:26:46.554 2009  PSFL left PSF tertiary mirror adjustMirrorCollimation complete for 0 seconds in the future
Fri Jan  9 23:26:47.627 2009  PMCL left PMC Hardpoint 3 lvdt is not showing any motion
Fri Jan  9 23:26:48.163 2009  PMCL left PMC Hardpoint 3 lvdt is not showing any motion
Fri Jan  9 23:26:49.248 2009  OSS oss.side[0].secondary_mirror: [moveAbs] complete
Fri Jan  9 23:26:49.316 2009  PSFL left PSF secondary mirror adjustMirrorCollimation complete for 0 seconds in the future
Fri Jan  9 23:26:54.522 2009  PMCL left PMC Mirror GoToPositionAbs Command Complete
Fri Jan  9 23:26:54.592 2009  PSFL left PSF primary mirror adjustMirrorCollimation complete for 0 seconds in the future
Fri Jan  9 23:26:56.679 2009  GCSL [gcs.command.autoAcquireGuidestar.triggered]
Fri Jan  9 23:26:57.193 2009  GCSL size: full CCD, exptime: 2000 ms
Fri Jan  9 23:27:01.499 2009  GCSL [gcs.interface.azcam.guider.readout.received]
Fri Jan  9 23:27:01.522 2009  GCSL [gcs.command.autoAcquireGuidestar.starDetection.started]
Fri Jan  9 23:27:02.179 2009  GCSL [gcs.command.autoAcquireGuidestar.starDetection.finished]
Fri Jan  9 23:27:03.204 2009  GCSL [gcs.interface.pcs.updateGuideOrigin.called]
Fri Jan  9 23:27:03.403 2009  PCS PCS UpdateGuideOrigin started - x 1.6178995e+01 and y 9.2777451e+01
Fri Jan  9 23:27:04.426 2009  PCS - Seconds of wait: 1.0000000e+00.
Fri Jan  9 23:27:04.452 2009  GCSL [gcs.interface.pcs.updateGuideOrigin.returned]
Fri Jan  9 23:27:04.471 2009  GCSL [gcs.guidethread.started]
Fri Jan  9 23:27:04.569 2009  GCSL [gcs.interface.azcam.guider.readout.requested]
Fri Jan  9 23:27:04.617 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:04.866 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:05.836 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:09.350 2009  GCSL [gcs.interface.azcam.guider.readout.received]
Fri Jan  9 23:27:09.704 2009  GCSL [gcs.interface.pcs.applyGuideCorrection.called]
Fri Jan  9 23:27:09.947 2009  PCS PCS ApplyGuideCorrection started on side 0: guideX 1.5877876e+01 and guideY 9.2802742e+01.
Fri Jan  9 23:27:09.984 2009  PCS PCS ApplyGuideCorrection complete on side 0: guideX 1.5877876e+01 and guideY 9.2802742e+01.
Fri Jan  9 23:27:09.989 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:10.038 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:10.050 2009  GCSL [gcs.interface.pcs.applyGuideCorrection.returned]
Fri Jan  9 23:27:10.569 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:10.629 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:10.729 2009  GCSL [gcs.interface.azcam.guider.readout.requested]
Fri Jan  9 23:27:10.876 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:11.140 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:11.156 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:11.310 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:11.431 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:11.648 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:15.504 2009  GCSL [gcs.interface.azcam.guider.readout.received]
Fri Jan  9 23:27:15.837 2009  GCSL [gcs.interface.pcs.applyGuideCorrection.called]
Fri Jan  9 23:27:16.004 2009  PCS PCS ApplyGuideCorrection started on side 0: guideX 1.5727285e+01 and guideY 9.2431442e+01.
Fri Jan  9 23:27:16.050 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:16.060 2009  PCS PCS ApplyGuideCorrection complete on side 0: guideX 1.5727285e+01 and guideY 9.2431442e+01.
Fri Jan  9 23:27:16.130 2009  GCSL [gcs.interface.pcs.applyGuideCorrection.returned]
Fri Jan  9 23:27:16.339 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:16.557 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:16.651 2009  GCSL [gcs.interface.azcam.guider.readout.requested]
Fri Jan  9 23:27:16.750 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:16.846 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:27:16.893 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:17.064 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:27:18.539 2009  GCSL [gcs.command.autoAcquireGuidestar.finished]
Fri Jan  9 23:27:18.579 2009  GCSL [gcs.command.startWFsensing.triggered]
Fri Jan  9 23:27:18.590 2009  GCSL [gcs.wfsthread.started]
Fri Jan  9 23:27:18.607 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: left PMC Mirror GoToPositionAbs Command Complete
Fri Jan  9 23:27:18.660 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: Ok
Fri Jan  9 23:27:18.713 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: Ok
Fri Jan  9 23:27:18.744 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: couldn''t adjust exposure time to meet low counts requirement. star too dim or guide rate too high.
Fri Jan  9 23:27:18.784 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: maximum exposure time is 4600 ms at the given guide rate, estimated counts are 799
Fri Jan  9 23:27:18.826 2009  IIF IIF Preset alert for left LUCIFER mode ACTIVE: adjusted exposure time to 4600 ms
Fri Jan  9 23:27:18.866 2009  IIF IIF Preset command complete with warnings for left LUCIFER mode ACTIVE from IIF

11:23:42 STEPFOCUS PROBLEM This is a different problem than described above. A stepfocus was received and GCS appears to have hung somewhere shortly after the pause guiding was received. Nothing in the IIF log appears to help figure this out.

Fri Jan  9 23:38:42.437 2009  IIF IIF StepFocus command started for left LUCIFER for 0.000000000000000e+00
Fri Jan  9 23:38:42.769 2009  GCSL [gcs.command.pauseGuiding.triggered]
Fri Jan  9 23:38:43.274 2009  GCSL pauseGuiding interrupted waiting for a guide image
Fri Jan  9 23:38:46.254 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:38:46.385 2009  GCSL [gcs.command.getWFImage.triggered]
Fri Jan  9 23:38:48.258 2009  GCSL [gcs.command.getGuideImage.triggered]
Fri Jan  9 23:38:48.419 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:38:48.591 2009  GCSL [gcs.command.getCentroid.triggered]
Fri Jan  9 23:38:48.816 2009  GCSL [gcs.command.getCentroid.triggered]

In the syslog, entries from GCS at this time...

Jan  9 23:38:42 lbtmu107 LBT_left_GCS: GCSL:pauseGuiding executed
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: set Zernike mode 18 to scale factor 0.000000
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: set Zernike mode 19 to scale factor 0.000000
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: set Zernike mode 20 to scale factor 0.000000
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: set Zernike mode 21 to scale factor 0.000000
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: set Zernike mode 22 to scale factor -1.600000
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: hotspot is reported to be 393.000000,220.000000
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: PROFILING: WFS: requesting image...
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: WFS: no image acquired as pauseLoop requested.
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: PROFILING: WFS: wait for image ended...
Jan  9 23:38:42 lbtmu107 LBT_left_GCS: WFS: pausing loop
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: pausing guide loop. timeout for loop to respond = 6600 ms. divided into 100 steps. wait per step = 66 usecs
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: Guiding: aborting waiting for image as a pause request was received..
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: guiding paused
Jan  9 23:38:43 lbtmu107 LBT_left_GCS: GCSL:pauseGuiding execution time: 685 ms at 1231569523454
Jan  9 23:38:45 lbtmu107 LBT_left_GCS: btr = 1
Jan  9 23:38:46 lbtmu107 LBT_left_GCS: GCSL:getCentroid executed
Jan  9 23:38:46 lbtmu107 LBT_left_GCS: GCSL:getCentroid execution time: 82 ms at 1231569526328
Jan  9 23:38:46 lbtmu107 LBT_left_GCS: GCSL:getWFImage executed
Jan  9 23:38:46 lbtmu107 LBT_left_GCS: WFS Cycle Time: 49.306980   WF Cam Exposure Time: 30000
Jan  9 23:38:46 lbtmu107 LBT_left_GCS: GCSL:getWFImage execution time: 101 ms at 1231569526486
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getGuideImage executed
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: effective Guide Rate: 0.180943 s  max. Guide Rate: 0.181038 s  at exposure time: 4600 ms   time4PCSxfer: 0.227343 s   time4ImgAcq: 4.817691 s
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getGuideImage execution time: 79 ms at 1231569528337
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid executed
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid execution time: 64 ms at 1231569528471
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getGuideCamPixelScale executed
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getGuideCamPixelScale execution time: 16 ms at 1231569528533
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid executed
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid execution time: 58 ms at 1231569528637
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid executed
Jan  9 23:38:48 lbtmu107 LBT_left_GCS: GCSL:getCentroid execution time: 87 ms at 1231569528891

Restarted GCS because the GCS log does not show any activity following reception of the pause guiding except a few image captures and centroiding (see above). We did not have to restart IIF and the subsequent preset completed successfully.

12:06 We have had a rapid drop in temperature outside and a corresponding jump in humidity. M1 temp = -2.2, T=-8.4, RH=80.9% The seeing has gone to heck as well.

12:27 An image taken after the PCS restart at 11:09 indicates we offset the LEFTZEROPOINT the wrong direction. The new LEFTZEROPOINT should be -187.726. PCS was restarted to read this new value. IE=-15 and CA=-5 restored. The bad weather and subsequent mirror panic (see below) prevented checking the final orientation.

~12:55 M1 panicked and Aaron is having trouble recovering. Calling John. Raising the air pressure did not work and Aaron thinks there is a bad valve that is leaking air at the back of the cell. Waking Jon Rousseau (2:00am) to see if he can figure out how to fix this. See below for more.

Proposed IIF.isGuiding flag logic for further discussion:

An IIF.isGuiding flag (comparable to the current isCollimated flag that should be moved to IIF/isCollimated) with appropriate logic would be useful for instruments to have available. For example, during a long spectroscopic integration if clouds interrupted the guiding cycle for some period of time the instrument would want to know this so it could write something like a data quality bit into the resulting image header, or use it to interrupt an ongoing exposure if necessary. A single lost guide image, especially at higher guider rates, would not be a problem. The goal is to provide a signal to the instrument that essentially says can they trust the guiding over some previous amount of time. I propose the following logic for this flag for further discussion with the instrument teams and LBT SW group:

IIF.isGuiding set to FALSE on all presets and offsets.
IIF.isGuiding set to FALSE for IDLE, TRACK, and ACQUIRE modes.
IIF.isGuiding initially set to TRUE on presets/offsets when guide star is within ~0.5 arcsec of the hotspot.
IIF.isGuiding changes to FALSE when the guide star is lost for whatever reason for some period of time.
Time to set FALSE is the longer of:
  • 10 consecutive guide cycles.
  • ~60 seconds driven by the open-loop tracking performance of the telescope.
Both of these numbers need to be set in a .conf file.

The 10 consecutive guide cycles is meant to average over single dropped frames or transient problems. The ~60 seconds is the period over which the open-loop tracking performance of the telescope can be trusted to keep the source in the same location without drifting off some configurable radial limit. That is to say the instrument can tolerate short periods with no guiding as long as it does not impact the delivered image quality (perhaps this should be called a DIQ flag?). One would therefore only set the IIF.isGuiding flag to false at the point where the DIQ starts to be affected.

The quick fix on the cell appears to not have been the source of the problem, and the cell is down for the rest of the night. Time lost to this telescope hardware problem is 7 hours. See IT#1947.

-- DavidThompson - 10 Jan 2009

This topic: Commissioning > Main > WebHome > Com20090110
Topic revision: 10 Jan 2009, DougMiller
This site is powered by FoswikiCopyright © by the contributing authors. All material on this collaboration platform is the property of the contributing authors.
Ideas, requests, problems regarding Foswiki? Send feedback