LUCIFER Com2
UT 2008 December 06

Observers: N.Ageorges, W.Seifert, P.Buschkamp, M.Juette, F.Eisenhauer, several others from LUCIFER team. D.Thompson (@LBT)
Telescope Operator: D.Gonzalez-Huerta
SW Support: M.DeLaPena in Tucson until 23.30.

Data will eventually be copied to /Repository/LUCIFER_Data/20081205/luci_20081205_NNNN.fits

Summary:

  • See Issue Trak #1883 (critical) . Found a mechanical obstruction of WFS light path.

  • Slow start, better than yesterday.
  • Several hangs of GCS-AZCam/AGW communications? Restarted of both.
  • Apparent hang of IRS-IIF or IRS-LUCIFER link? Command from LUCIFER not seen in IRS logs. Restarted both.
  • Spontaneous reboot of azcam computer, not by us? 07:36:08 agw-control syslogd 1.4.1#18ubuntu6: restart.
  • Large 10-20 arcmin offsets out of the patrol field and back hit the guide box and resume guiding/WFSing.
  • Offsets outside of patrol field should issue warnings, not errors back to the instrument.

  • Intent is to be open and ready by sunset-1Hr (~4:30pm) Saturday night.
  • Tom/Johannes may call to request the DIMM be powered up (only if they call).

Details:

Note: Chase issues on preset will normally be cleared on the subsequent Step Focus command.

05:59:00.000 Logging into the wiki starts.

05:59 Track mode preset resulted in an AGw parkActiveProbe failure. Stopping and restarting AGw, homing motors

06:05:00 We are running on the new collimation model taken 2 nights ago at 0C and the outside temperature is -0.3 degrees. All active optics have been cleared from M1 and M2 and yet we see significant coma and defocus. See luci#0011.

06:08 Initial IE = -2.90000 CA =16.35000 adjusted to IE = -35.90, CA = 7.35000 (PTMODEL has IE = -14.91, CA = -10.65, so we did not re-read the pointing model at the start of the night).

18:11:43 StepFocus failed due to GCS not pausing within the timeout period. GCS appears to have hung but we re-sent the preset 18:16:22.03 and it succeeded. GCS complains the guide star saturates in its minimum exposure time (500ms). It was a pointing model star (V~7.5) so this message was correct.

18:18:55.230 Preset to off-axis guide star...WFS appears not to be working. AZcam issue? Stop & restart AGW, GCS. Someone or something just rebooted the agw-control computer.
Dec 5 07:36:08 agw-control syslogd 1.4.1#18ubuntu6: restart.
but /var/log/boot says: Dec 4 16:16:22 rc2: * Running local boot scripts (/etc/rc.local) [ ok ] As near as I can tell, agw-control did not reboot, so where did the messages come from?

18:30:43 Preset sent again. GCS is waiting for an image for 2 minutes+ now. GCS killed and "mostly went down" but did not stop entirely.

18:34:57.187 Preset sent again, succeeded, using GS as wfs reference. WFS seems to be having trouble converging. Vent doors were open, SMT weather shows ~4m/s peak over the last hour.

18:47:24.974 Preset to off-axis GS, completed. First WFS image shows 350nm rms. Guider is showing ~1.75 arcsec FWHM.

18:52:03.603 2008 Preset to first program field. LUCIFER team conducting dither/offset tests. 390nm on first WFS image, 1.36 arcsec FWHM on guider.

Dec 5 18:59:50 lbtmu107 LBT_left_GCS: GCSL:pauseGuiding execution time: 48 ms at 1228528790575. The dither took the guide star out of the patrol field, so the system is doing what it is supposed to do. However, the status bars on GCSGUI stay green, I would suggest they turn yellow.

GCS died for no obvious reason:
19:12:26 lbtmu107 LBT_left_GCS: ~azcam: calling closeSocket()
19:12:32 lbtmu107 LBT_networkserver: GCSL died unexpectedly

GCS was restarted and at 19:14:04.994 Preset reissued from LUCIFER

19:4713 Offset command sent from LUCIFER but not received by IIF. There are no log messages in syslog for IRS since the StepFocus completed at 19:44:32.

~20:03:02 LUCIFER stopping and restarting their services to see if it will reconnect to IRS. It cannot connect. It fails to get back the ICE handle.
~20:08:38 IRS only was restarted, not IIF. LUCIFER now can connect with IRS.

20:13:12.620 Preset sent from LUCIFER...telescope is slewing. Preset and Step Focus were successful. Current fix suggestion if this happens again is to restart IRS and LUCIFER's telescope service but not IIF. Re-authorization on LUCIFER's side is necessary.

Note: I am monitoring the syslogs for various subsystems with the following:
GCS
tail -f messages | grep GCS | grep -v WFS | grep -v utex | grep -v getCentroid | grep -v getGuideImage | grep -v PROFILING | grep -v Scale
tail -f messages | grep WFS | grep -v "scale factor" | grep -v PROFILING | grep -v "z("
IRS
tail -f messages | grep IRS | grep -v Multi | grep -v OSS | grep -v Mutex
IIF
tail -f messages | grep IIF | grep -v Multi

20:17:49 FWHM_guider = 1.5 arcsec, WFS=382nm rms. Polaris monitor is showing 3.56 arcsec FWHM! Outside 0C, 8m/s wind from our WS, 25% RH.

20:24:56 LUCIFER-IRS communication appears to be hung again.

20:27 Stopped IIF, 20:27:52.851 IIF restarted, stopped and restarted IRS.
20:32:33.990 LUCIFER authorized. They had to restart (kill) their telescope service.
Michele can find no socket errors or any other indication of a problem in the logs.

Note to self: don't ^w in the wiki. Lost some unsaved notes.

21:21:00.321 Preset failed because guide probe could not reach position (wrong PA)

21:21:47.788 Preset failed. Star is on acquire000085 in LL corner, but only ~25DN above background.

From GCS log (This is just for increasing clarity in log messages and improve my understanding. GCS did not find the star at 65,30 because it was just too faint):
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: acquisition image saved as /tmp/acquire000085.fits
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: maxWindowSize = 494
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: mean bkgrd of acquisition image is: 1270.3, stddev: 5.3, 6 * stddev: 26.4 *6 x 5.3 = 31.8*
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: windowsize around hotspot is 80.
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: subtracting background noise for WWPA guide image: 1274
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: WWPA centroid, verifying star does exist...starpix(avg'ed over 5x5, max/min removed) = 2.33
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: 5.0 times stddev of bkgrd noise is 13.2
Dec 5 21:23:21 lbtmu107 LBT_left_GCS: star was not bright enough around center(288,250) to be accepted: count = 2.3, threshold = 100.0
_>> This sounds like GCS thinks it found a star, but in fact it did not._
Dec 5 21:23:24 lbtmu107 LBT_left_GCS: star was not bright enough around center(244,259) to be accepted: count = 5.0, threshold = 100.0
>> Does this mean GCS thinks there is a star at 244,259? Also these center() comments in the logs have coordinates jumping all over the place.

21:24:48.544 Preset in TRACK/PARALLACTIC to correct pointing. IE changed from -35.9 to -58.100 CA changed from 7.35 to 12.15.

Rotator center on LUCIFER is at coords 1025, 1050

21:45:49.13 This offset command should have brought us back to the starting position but IIFGUI is reporting:
21:45:53.495 Offset failure for left LUCIFER: error: setProbePosition: couldn't move probe to position (SFP) (x,y,z): 8.65268, -95.8198, 27.0218 mm.
A getStatus on agw-control reports stages at AGW probe is at (x,y): -8.702, 95.828 mm and a LUCIFER image (luci#143) does show the telescope and probe consistent with this position. So the question is why did the guider fail to start guiding again?

We restarted nothing and sent a new preset at 22:03:42.693 that succeeded.

wfscimage000856.fits time of observation: 05:05:05.78
Note that the wfscimages here look odd. There is a strong gradient in flux across the pupil, see attached jpeg. This gradient was present to some extent in the previous pointing (wfscimage#855) but more pronounced in #856 and following. The images on the guider and LUCIFER clearly show a tail. Are we off-center on the hotspot/wfs entrance aperture now?

pupil.jpg

Frame #847 looks OK, as do the others taken at this position. although it has some scattered light at the edge that we think is from a nearby bright star. The vignetting may start to show up in image #852, taken at 04:29:26.82.

22:33:42.469 New preset from LUCIFER to a different source. The WFS image has a lot of scattered light and/or reflected pupil spots in it (#884 at 05:35:45.44 through #892 at 05:44:13:33. See the attached image. A change of guide star on the same source but 90 degrees away also showed the scattered light. A third guide star at PA=180 looks clean but there is some vignetting on the pupil as the guide star is 4.03 arcmin off axis. We checked the acquisition images and all show no other sources or scattered light. Walter is checking in the dome for a stray light source...could be moonlight as it is shining directly on the head of the AGW? No other obvious light sources in the dome.

pupil2.jpg

23:05:55 GCS is taking 0.5s exposures here and we are getting a warning that the guide cam exposure time is below the lower limit. The guide stars only have ~8000DN so I am not sure why the warnings are being issued. As long as the star has peak counts below ~45kDN it should not issue the warning. In the guide-faster to keep up with the telescope drifts mode, 0.5s exposure time is acceptable.

At this position, LUCIFER is continuing with offset tests. The guider is seeing ~0.7 arcsec FWHM, the WFS is running around 300nm rms/cycle.

Dec 5 23:37:54 lbtmu107 LBT_left_GCS: GCSL:resumeGuiding executed
Dec 5 23:37:54 lbtmu107 LBT_left_GCS: resuming guide loop.
Dec 5 23:37:54 lbtmu107 LBT_left_GCS: guiding resumed
Dec 5 23:37:54 lbtmu107 LBT_left_GCS: >>>>>>>>>>>>>>>>>>>>>>>>> next guide iteration <<<<<<<<<<<<<<<<<<<<<<<<<<<
Dec 5 23:37:54 lbtmu107 LBT_left_GCS: GCSL:resumeGuiding execution time: 7 ms at 1228545474970
Dec 5 23:37:54 lbtmu107 LBT_left_GCS: error requesting an image in GuidingThread. Lost connection?

23:38:55 Stopped GCS, stopped and restarted AGW, homed motors, restarted GCS. First instance of a lost connection was 23:25:12.

23:43:09.969 Preset completed, but initial collimation was bad. We stopped WFS, cleared all active optics and there was significant focus. Applied -0.2mm to M1 and then restarted WFS. Converged to 296nm on 4th iteration.

12:42 LUCIFER has been running offsets on this field for an hour.

00:34:47.379 Preset to astrometric field (AF_PA100). Same field as observed yesterday for check of the astrometric stability (luci#206-259, dated 20081204 because this was set in the script. The data will be in with the rest from 20081205 [UT20081206]).

01:40:01.817 Preset 01:48 we are hung somewhere again... The preset is seen on IIF but nothing appears to be happening on the TCS side (telescope did not move, etc.). We shut down IRS, shut down and restarted IIF, then started IRS.

02:15:33.080 Step Focus is taking too long (02:18:19). Similar to the last one...the StepFocus is seen by the IIF but nothing seems to be happening on the TCS side.

The last command logged by GCS was: 02:14:37 lbtmu107 LBT_left_GCS: centx: 289.888809, centy: 253.211533, xf: 50.888809, yf: 51.211533,peak: 5465.000000, mbg: 1277.083333

We stopped GCS, stopped and restarted AGW (for no obvious reason), homed the motors, then restarted GCS. The preset then worked.

WFS image has very low SNR. It looks like acquisition picked up the wrong star. See acquire000099.fits, there are three stars in the image. The star at 493,317 is probably the correct guide star, but the star at 232,141 (the faintest!) is the one picked up as it was closest to the hotspot.
Dec 6 02:27:44 lbtmu107 LBT_left_GCS: found guide star in image at 230.367676,139.482132.
The chosen star was OK for guiding, but had too low counts on the WFS images.

02:54:00 The WFS is again very unevenly illuminated, see attached image. It seems stable over multiple WFS cycles. The guider is keeping the star centered but the seeing is 1.5-2.0 arcsec FWHM and the image is obviously aberrated. There is nothing obviously wrong: active optics corrections on M1 and M2 look reasonable and we are running in the default mode (focus and coma to M2 with offloading). I suspect the prior faint wfs star built up a bit of M2 offload that was affecting the later collimation.

03:05:10.715 Preset sent from LUCIFER. During slew we cleared active optics and M2 offload. Initial guide image was out of focus and comatic. Initial WFS correction was 1953nm, 1427 (mostly focus), 1280 (mostly focus), 892 (includes Z4-Z11), 450, 464... Collimation claims to be below 300nm but the guide image has a large tail to it and the WFS images look like this (wfsc#1068):

pupil4.jpg

and getting worse. Most of the observations were taken at non-zero X coordinates, we are currently suspecting that the Zernike rotation compensation is not correctly accounting for the WFS detector rotation at non-zero X coordinates.

03:36:48.776 Preset failed...guide star not found (something there, but faint and aberrated).
03:39:29.174 Preset to pointing star in TRACK/PARALLACTIC mode to correct pointing IE now -61.7 and CA now 1.35 (~11 arcsec change from before).

03:44:51.164 Preset to on-axis WFS reference star, starting from the highly aberrated state from before. After several cycles it does not seem like it is collimating anything.

03:51 Stopping GCS, stop and restart AGW, home motors, restart GCS. We confirmed on 107 that GCS was actually dead, with no processes named GCS anything, but: there was this process running:

1033 16928 0.0 0.4 10716 4236 pts/1 S Dec05 0:00 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu01 -font 6x13 -e /usr/bin/perl -e ??m y $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);??? print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/w39rQpZs7p lbtmu01 1033 16929 0.0 0.4 9300 4184 pts/1 S Dec05 0:01 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu101 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/sT4VwqX8Bn lbtmu101 1033 16930 0.0 0.4 10116 4324 pts/1 S Dec05 0:10 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu102 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/SLStEnjUOr lbtmu102 1033 16931 0.0 0.4 10396 4204 pts/1 S Dec05 0:00 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu103 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/mhBqfJKgNp lbtmu103 1033 16932 0.0 0.4 10724 4204 pts/1 S Dec05 0:00 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu104 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/zGfG8z2PSh lbtmu104 1033 16933 0.0 0.4 10592 4420 pts/1 S Dec05 0:17 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu105 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/o6zYLaUGmk lbtmu105 1033 16934 0.0 0.4 10176 4396 pts/1 S Dec05 0:09 /usr/bin/xterm -xrm XTerm.VT100.allowSendEvents:true -T CSSH:lbtmu107 -font 6x13 -e /usr/bin/perl -e ?? my $pipe=shift;???my $svr=shift;???my $user=shift;???my $port=shift;???$user = $user ? "-l $user" : "";???$port = $port ? "-p $port" : "";???open(PIPE, ">", $pipe);?? ?print PIPE "$$:$ENV{WINDOWID}";???close(PIPE);???if($svr =~ /==$/)???{????$svr =~ s/==$//;????warn("??WARNING: failed to resolve IP address for $svr.??".?????"Either ignore_host_errors or -i is set. This connection may hang???"????);???}???exec("/usr/bin/ssh -x -o ConnectTimeout=10 $port $user $svr");? /tmp/jXpjDDBitg lbtmu107

What the heck is this stuff???

04:03:03.639 Preset sent with GS on-axis. All active optics and M2 offloads cleared on M1, M2. We started out with coma and defocus (1100nm) and the wfs rms reduced with the first few cycles, but the WFS pupil remained unevenly illuminated (and different than before). We are parking at zenith and Walter went to see if there is any obvious problem in the visible AGW optics. He found that there is an empty holder of some sort between the fold mirror and the entrance aperture of the WFS that is loose and had twisted into the beam from the telescope. Unless this is a critical piece, we suggest it be removed. See Issue Trak #1883 (critical) . I emailed Jesper to find out how critical this piece is, but we will likely remove it tomorrow afternoon even if we do not hear from him.

Another ^w, darn it.

04:46:16.807 More preset/offset tests at low EL~27 degrees. Guider sees 1.5-2.0 arcsec FWHM, occasionally better. WFS converges to ~300nm/cycle.

This apparently came through from Marcus:
Sat Dec 6 05:28:31.537 2008 Authorize command started for left IRTC at bentGregorianFront focus (IIF left side)
Sat Dec 6 05:28:31.552 2008 Authorize command failed for left IRTC at bentGregorianFront focus (IIF left side)
Marcus will contact Jose about this.

05:30:02.274 Preset command started for left LUCIFER mode ACTIVE, failed (guide star off bottom of acquisition image #110

Corrected pointing IE now -72.5 and CA now 6.75

05:36:44.215 Preset failed. Guide star centered in acquire image #111 but low counts and out of collimation. Applied +0.1mm Z to M1 and subsequent preset failed (went the wrong way). Applied -0.1mm Z to M1, preset succeeded but low counts.

05:46:08.935 Authorize as IRTC is from Jose connecting remotely. His connection is blocked whenever LUCIFER is presetting/offsetting. So the conclusion is that the multi-client IRS is not functioning as expected.

-- DavidThompson - 05 Dec 2008
Topic attachments
I Attachment Action Size Date Who Comment
pupil.jpgjpg pupil.jpg manage 10 K 06 Dec 2008 - 05:19 DavidThompson  
pupil2.jpgjpg pupil2.jpg manage 28 K 06 Dec 2008 - 05:45 DavidThompson  
pupil4.jpgjpg pupil4.jpg manage 10 K 06 Dec 2008 - 10:17 DavidThompson  
Topic revision: r5 - 06 Dec 2008, MicheleDeLaPena
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