Date: Wed, 10 Jul 2002 11:05:26 GMT From: harvanek@apo.nmsu.edu (Mike Harvanek) Subject: 2.5m obslog 20020709 (MJD 52465) APACHE POINT OBSERVATORY SDSS 2.5M OBSERVING LOG Tuesday July 9, 2002 (MJD 52465) ---=== OBSERVING TEAM ===--- Mike Harvanek (APO) Daniel Long (APO) Scot Kleinman (APO; swing) Jon Brinkmann (APO; by phone) Craig Loomis (APO; by phone) ---=== OBSERVING PLAN ===--- Science! ---=== OBSERVING SUMMARY ===--- Two plates finished (1043, 990) and good data obtained for another two plates (1052, 717). Problem with the sp1 camera. ---=== OBSERVING LOG ===--- Mostly clear at sunset. We began with spectroscopy. Plate 1043 (cartridge 4): Guide stars on the gotoField. The 2nd exposure (15860) had a bad exposure time which was fixed with APOFIX. The correct exposure time is 900s. This plate was finished in three 15 minute exposures. Plate 1052 (cartridge 5): Guide stars on the gotoField. The 1st exposure (15865) had a bad exposure time which was fixed with APOFIX. The correct exposure time is 900s. There was a problem with the sp1 camera at some point during the 2nd exposure and it failed to read out. Nor could we start another exposure because the camera thought it was still taking the 2nd exposure. See the Problems section for details. By the time this problem was resolved, this plate had expired. Plate 990 (cartridge 9): No guide stars on the gotoField. Offsets cleared but still no guide stars. An FK5 star was found about 10" off in one direction and 5" off in the other direction. Guide stars were obtained after applying the FK5 offsets. This plate was finished in 4 exposures (70 minutes total exposure time). Plate 717 (cartridge 2): Guide stars on the gotoField. Two good exposures obtained before the sky became too bright. When putting the telescope away, we noticed that the rotator and both alt 1 and alt 2 slip detection lights had gone off. We logged them on the log sheet and reset them. ---=== IMAGING RUN SUMMARY ===--- Run Time Stripe Lambda Last Flavor Comments Start End Begin End Frame ------------------------------------------------------------------------- ---=== IMAGING RUN DETAILS ===--- ---=== SKIPPY RESULTS ===--- Run Frame nFrames stars muErr muRms nuErr nuRms rot az el --------------------------------------------------------------------------- ---=== LTMATCH RESULTS ===--- Run Field nFields alt az nGood rowMean rowSig colMean colSig rot ---------------------------------------------------------------------- ---=== SPECTROSCOPY DATA SUMMARY ===--- UT Exp Time flavor comment (S/N)^2 totals ========================================== b1 r1 b2 r2 ----- sequence 15855, plate -9999 ------- 00:05 15855 0.0 bias 02:05 15856 0.0 bias ----- sequence 15857, plate 1043 ------- 17.8 18.0 17.9 20.3 DONE 03:21 15857 10.0 flat 03:23 15858 2.0 arc 03:42 15859 900.0 target 04:00 15860 21765.0 target exptime=900s 04:18 15861 901.0 target 04:26 15862 240.0 smear ----- sequence 15863, plate 1052 ------- 5.3 5.6 5.2 5.3 04:43 15863 10.0 flat 04:45 15864 2.0 arc 05:03 15865 23236.0 target exptime=900s ----- sequence 15866, plate -9999 ------- 07:23 15866 0.0 bias 07:26 15867 0.0 bias 07:31 15868 0.0 bias ----- sequence 15869, plate 990 ------- 16.3 18.6 15.3 25.3 DONE 07:57 15869 10.0 flat 08:00 15870 2.0 arc 08:18 15871 901.0 target 08:41 15872 1202.0 target 09:03 15873 1201.0 target 09:10 15874 240.0 smear 09:28 15875 901.0 target ----- sequence 15876, plate 717 ------- 10.2 12.6 8.7 14.7 09:44 15876 10.0 flat 09:46 15877 2.0 arc 10:07 15878 1000.0 target 10:29 15879 1200.0 target ---=== TELESCOPE OFFSETS AND SCALE I ===--- Time Instrument Az Alt Rot Scale pos offset pos offset pos offset ------------------------------------------------------------------------------ 03:12Z 4 1043 212.24 -0.0016 64.33 0.0012 47.80 -0.0088 1.000070 04:52Z 5 1052 231.80 -0.0012 70.33 0.0015 65.00 -0.0229 1.000040 08:01Z 9 990 38.28 0.0022 50.54 -0.0035 211.35 0.0068 0.999990 09:57Z 2 717 -1.39 0.0028 48.91 -0.0010 178.79 0.0030 1.000030 ---=== TELESCOPE OFFSETS AND SCALE II ===--- ---=== DATA TAPE SUMMARY ===--- Goes: JL5440 Stays: JL5441 ---=== FOCUS LOG ===--- setmir piston Temp Wind Time Inst scale M1 M2 Foc Az Alt (C) MPH Dir filt fwhm ------------------------------------------------------------------------------- 03:11Z 4 1043 1.00007 -690 380 -190 212 64.5 15.5 12 162 ---- 1.7 04:51Z 5 1052 1.00004 -394 623 -180 232 70.4 13.8 22 132 ---- 1.9 07:59Z 9 990 0.99999 99 1082 -180 39 50.3 13.1 11 125 ---- 2.1 09:57Z 2 717 1.00003 -295 749 -190 -2 48.9 14.0 0 192 ---- 2.0 ---=== WEATHER LOG ===--- Wind Time Temp F Dewp F MPH Direction Dust DIMM Sky 23:07Z 54 46 8 76 (ENE) 954 - Light Rain 23:39Z 59 47 10 154 (SSE) 1001 - Partly Cloudy 00:11Z 61 49 12 150 (SSE) 1223 - Partly Cloudy 00:43Z 62 45 9 175 (S) 986 - Mostly Clear 01:15Z 61 43 4 148 (SSE) 824 - Mostly Clear 02:18Z 59 40 14 154 (SSE) 813 - Mostly Clear 02:48Z 59 40 12 149 (SSE) 818 - Mostly Clear 03:18Z 60 41 12 156 (SSE) 864 - Partly Cloudy 03:49Z 58 42 14 144 (SE) 992 - Mostly Clear 04:21Z 57 44 19 128 (SE) 1240 - Mostly Clear 04:52Z 56 44 21 128 (SE) 1245 - Mostly Clear 05:24Z 56 42 19 128 (SE) 1273 - Mostly Clear 05:56Z 56 42 16 122 (ESE) 1316 - Clear 06:29Z 55 42 15 124 (SE) 1215 - Clear 07:02Z 55 41 8 97 (E) 1258 - Clear 07:33Z 55 40 11 113 (ESE) 1265 - Clear 08:04Z 55 40 8 109 (ESE) 1292 - Clear 08:37Z 56 40 7 122 (ESE) 1259 - Clear 09:10Z 55 40 5 106 (ESE) 1282 - Partly Cloudy 09:42Z 57 40 0 204 (SSW) 1281 - Partly Cloudy 10:12Z 57 40 2 153 (SSE) 1278 - Partly Cloudy 10:43Z 55 39 8 121 (ESE) 1187 - Mostly Cloudy ---=== TELESCOPE STATUS ===--- 01:10 Doors open, fans on 02:10 Enclosure off 10:45 Enclosure on, doors closed, fans off. Telescope stowed at 30 degrees with cartridge 2 (plate 717) mounted. Counterweights at 280. Spectro auto-fill connected. Imager dewar 11:00 69 lb Spectro dewar 11:00 122 lb Alt, az slip detection interlocks bypassed. ---=== SOFTWARE USED ===--- IOP/SOP: v3_81_1 Watcher: v2_18_0 MCP: v5_13_0 TPM: tpm_v2_14_0 AstroDa: v14_47 TCC: 2.6.5 sdssProcedures: v1_50 tccMon : v1_9 SoS: v4_9_10 hoggPT: v1_5_8 plate-mapper: v4_1_0 ---=== MIRROR NUMBERS ===--- PRIMARY: -------- Scale: 1.000000 MIGS TONIGHT NOMINAL Axial A 0.0880 0.0860 Axial B 0.8040 0.8050 Axial C 0.0740 0.0760 Trans D -1.5310 -1.5230 Lateral E 1.8320 1.8300 Lateral F 0.0000 0.0000 GALILS Commanded: 5400. -3700. 900. -200. 31550. 30650. Actual: 5400. -3700. 900. -200. 31550. 30650. SETMIR VALUES PriDesOrient: 0.00 -11.80 23.00 1256.90 642.10 PriOrient: 0.00 -12.16 22.81 1257.41 642.19 SECONDARY: ---------- Focus: 0.00 Air Temp.: 16.4 Alt.: 29.998639 MIGS TONIGHT NOMINAL Axial A 1.5360 1.5380 Axial B 1.2050 1.2080 Axial C 1.1500 1.1510 Trans D -0.6230 -0.6200 GALILS Commanded: 1604776. 1575863. 1570824. -12000. -11350. Actual: 1604800. 1575850. 1570850. -12000. -11350. SETMIR VALUES SecDesOrient: 1257.00 5.00 -10.00 0.00 165.44 SecOrient: 1257.00 5.00 -9.98 -0.23 165.34 ---=== PROBLEMS IN DETAIL ===--- Problem with SP1 camera: ------------------------ 05:20Z second science exposure failed to read out claiming sp1 was busy. endStare got same response that sp1 was busy. readoutAbort didn't help ( daqBusy wasn't high anyway ). starting another exposure failed because sp1 failed to stop scanning. connecting to the port for sp1 camera ( 2100 ), connected but there was no response to input. sp2 was fine. A quick check of the serial cable to sp1 showed it was connected. It was reseated anyway. All power supply voltages looked good as well. A call was placed to Jon Brinkmann at about 05:45Z. He said it was OK to reboot the camera micro by power cycling, which we did. Once the camera was up, we logged in to the port and were able to get the normal ok response. It also responded to commands. After a minute or so it commands and responses began scrolling across the telnet window to the port. We weren't issuing them. Breaking that connection and going to sp2 showed everything normal there. No unsolicited commands. So there was nothing funny with our xterm and or telnet session. Returning to sp1 showed the same character ( this time a { ) was streaming across the screen followed by repeated undefined command responses from the micro. The cursor was bouncing all around the window during this. Finally the micro stopped doing anything and would not respond to input. We went through several reboots and would get part way through getting started again, only to have the micro stop talking at some point. It seemed that commands were getting through the telnet session to sp1 on port 2100. We tried killing the spectro server. This appeared to help. We could get further in restoring normal operation. We could talk to the micro and not get unsolicited characters. However we couldn't get it to take an exposure. Each time we tried the sop session would get file 9 or file 8 errors or say the spectrograph was unwilling to stop scanning. We then tried calling Craig ( ~ 06:30Z ), as it seemed the terminal server was passing multiple connections to the same port. After doing some checking, he had us swap cables between the two spectro cameras. We did this at the patch panel in the lower enclosure, and again at the mux on the rotator. Each time it indicated the problem was closer to the spectrograph. So apparently the gibberish from the micro and the servers restarting was only coincidence. We then called Jon again at around 07:00Z. It seems that the problem really was in the micro. At this point we had power cycled it several times and it would only last a few minutes before failing, and once it didn't even come up. As one last test Jon had us disconnect and reconnect the serial cable at the spectrograph, then power cycle again. This time it came up and took the iack with no problem. A telnet connection worked without extra characters, even when the servers came back up. Bias exposures worked. We were back in business. Whether we actually fixed the problem by disconnecting and reconnecting the serial cable at the spectrograph, or the problem just went away while we were trying things, only time will tell. While a loose connection ( and/or broken wire within the cable ) can generate noise on the line which would be seen as random characters, it is tough to understand how legitimate commands and subsequent responses show up in a telnet session to the micro which weren't typed into the window. Below are excerpts from the sop session, tracebacks, and error messages. The first indication of failure: mcpPut: SYSTEM.STATUS SOPGUI: doNextScience 900 mcpPut: ffs.open mcpPut: SYSTEM.STATUS Opened Flat Field Screen Issuing goStare science with 900 exposure sp1 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 sp2 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 Flushing charge for 15 sec mcpPut: SYSTEM.STATUS appending BEGIN scheduling a routine to wait until the exposure is finished successfully started science exposure mcpPut: SYSTEM.STATUS IOP running as Backup Relay Server requestListen: listening 2002-07-10 05:08:56Z 35 sp1 camcheck 2002-07-10 05:08:58Z 35 sp2 camcheck 2002-07-10 05:09:04Z: registered (addr19) listener sdsshost:observer:4875 IOP running as Backup Relay Server requestListen: listening 0 2002-07-10 05:19:52Z: registered (addr20) listener sdsshost:observer:4875 =====endStare: beginning read out ============================= appending END EXPOSURE TIME is: 900 sp1 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 2002-07-10 05:20:18Z: sp1 is not idle...aborting 2002-07-10 05:20:18Z: beginData has failed: sp1 is not idle...aborting sp1> tb sp1 is not idle...aborting while executing "error $msg" invoked from within \042if {$status != \042IDLE\042} { set msg "$camName is not idle...aborting" murmur $msg $toScreen error $msg }\042 ("foreach" body line 3) invoked from within \042foreach camName [activeInstruments] { set status [keylget returns $camName] if {$status != \042IDLE\042} { set msg "$camName is not idle...abortin ..." invoked from within \042if { $cameraType !=\042sim\042 } { set returns [camExec [activeInstruments] cameraNag] foreach camName [activeInstruments] { set status [k ..." (procedure "beginData" line 38) invoked from within "beginData $noIncrSeq" invoked from within "endStare -timeout 80 -noIncrSeq" ("eval" body line 1) invoked from within "eval endStare $imageName -timeout $readoutTimeWait $flags " (procedure "wait_for_endStare" line 64) invoked from within "wait_for_endStare {sp1 sp2} {} 80 1 0 1 0 0" ("eval" body line 1) invoked from within "eval $procname $args" sp1> sp1> goStare -init -bias A [cc ping] brings no response from sp1: electronics powered down? 2002-07-10 05:32:47Z: Choosing staring readout mode 2002-07-10 05:32:47Z: Set frames to Rows=(2048+21) and Cols/2=(20+1024+20) Binning=(1,1) sp1 camstat {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 camstat {} t-g-sdss-2.apo.nmsu.edu 2200 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2100 sp1 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2100 setupCamera {SPEC2 27FEB01 $Name: v4_7 $} t-g-sdss-2.apo.nmsu.edu 2200 sp2 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2200 Error: sp1: camera not willing to stop scanning sp1> Trying to connect to the camera micro: > telnet t-g-sdss-2 2100 Trying 192.41.211.163... Connected to t-g-sdss-2.apo.nmsu.edu. Escape character is '^]'. telnet> quit Connection closed. > telnet t-g-sdss-2 2200 Trying 192.41.211.163... Connected to t-g-sdss-2.apo.nmsu.edu. Escape character is '^]'. ok ok ok ok ok telnet> After sp1 camera power cycle: sp1> iack 2002-07-10 06:15:02Z: BIAS DACS SET 2002-07-10 06:15:03Z: BUFFERS SET 0 sp1> sp1> goStare -init -bias 2002-07-10 06:16:23Z: Choosing staring readout mode 2002-07-10 06:16:23Z: Set frames to Rows=(2048+21) and Cols/2=(20+1024+20) Binning=(1,1) sp1 camstat {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 camstat {} t-g-sdss-2.apo.nmsu.edu 2200 setupCamera {error writing "file9": Bad file number} t-g-sdss-2.apo.nmsu.edu 2100 sp1 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2100 setupCamera {SPEC2 27FEB01 $Name: v4_7 $ } t-g-sdss-2.apo.nmsu.edu 2200 sp2 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2200 sp1 cameraDetach {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 cameraDetach {} t-g-sdss-2.apo.nmsu.edu 2200 Error: sp1: camera not willing to stop scanning sp1> goStare -init -bias 2002-07-10 06:18:56Z: Choosing staring readout mode 2002-07-10 06:18:56Z: Set frames to Rows=(2048+21) and Cols/2=(20+1024+20) Binning=(1,1) sp1 camstat {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 camstat {} t-g-sdss-2.apo.nmsu.edu 2200 setupCamera {SPEC1 27FEB01 $Name: v4_7 $ } t-g-sdss-2.apo.nmsu.edu 2100 sp1 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2100 setupCamera {SPEC2 27FEB01 $Name: v4_7 $ } t-g-sdss-2.apo.nmsu.edu 2200 sp2 setupCamera {} t-g-sdss-2.apo.nmsu.edu 2200 2002-07-10 06:19:12Z: Setting sp1 up for data taking 2002-07-10 06:19:12Z: Setting sp2 up for data taking 2002-07-10 06:19:12Z: Setting group(=run) to 52465 and frame to 15865 sp1 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 Flushing charge for 15 sec mcpPut: SYSTEM.STATUS appending BEGIN appending END EXPOSURE TIME is: 0 sp1 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 sp2 cameraNag {} t-g-sdss-2.apo.nmsu.edu 2200 2002-07-10 06:20:22Z: sp1 is not idle...aborting 2002-07-10 06:20:22Z: beginData has failed: sp1 is not idle...aborting sp1 cameraDetach {} t-g-sdss-2.apo.nmsu.edu 2100 sp2 cameraDetach {} t-g-sdss-2.apo.nmsu.edu 2200 Error