APACHE POINT OBSERVATORY SDSS 2.5M OBSERVING LOG Friday May 8, 2009 (MJD 54960) ---=== OBSERVING TEAM ===--- Dmitry Bizyaev Dan Oravetz Jon Brinkmann (support) ---=== OBSERVING PLAN ===--- Science! ---=== OBSERVING SUMMARY ===--- Clear skies with full moon and good seeing for most of the night. Around 09:20Z the wind direction shifted and the wind speeds picked up bringing a drop in temperature, increased humidity, and increased dust counts. We tested windshields and determined that pollen was a contributing factor to the increased dust counts, so we immediately closed, but it seemed to have come hard and fast. Please check the mirror. Observed: Cart. 5, 3413A, HD88133 Cart. 6, 3416B, HD89744 Cart. 6, 3416A, HD89307 Cart. 3, 3277B, GJ436 Cart. 8, 3359B, K15 Suspect fibers were seen in 5 A & 6 B. See log for details. We had problems with sdsshost2 in the afternoon due to a configuration problem with the DNS server, but Jon fixed it. I had a problem with my MJCI session, but the "Re-Connect" button eventually fixed it. This appeared different from the connection errors that we've been having. We did not experience any of the connection errors we have been having tonight. We had another timeout during instChange. Details are in the Problems section. Does anyone know why sp1 would have had cameraDown issued? Anyway it's back to "up" now. Again, details in log. All of the sessions at the telescope laptop vanished. Details in log. ---=== OBSERVING LOG ===--- Afternoon ========= Turned on the ThAr lamp. When we came in this afternoon we had some problems with sdsshost2. Dmitry was able to ssh in from landru normally, but he was unable to properly run Watcher as it timed out on each attempt. I was unable to log into sdsshost2 from the MONX terminal adjacent to landru. At first, when MONX asked for the XDM session, it hung and subsequently MONX was not showing sdsshost2 as an available host to begin with at the login menu. Jon tracked the problem down to a configuration problem on the main server due to some changes made this afternoon, but Jon was indeed able to fix things. sdsshost2 was rebooted in the process, but it was in need of a reboot anyway. sdsshost2.apo.nmsu.edu % df -h Filesystem Size Used Avail Use% Mounted on /dev/sda3 142G 118G 18G 88% / /dev/sda1 99M 30M 64M 33% /boot /dev/sdb1 917G 744G 127G 86% /data sdssfiles1p:/data1/data 1.5T 603G 790G 44% /files We did not get a chance to run goSpecFocus and check the spectrograph temperature settings due to the late start from the sdsshost2 problems. 01:25Z - Began ventilation. Mounted cart. 5. Checked fiducials and mirror numbers. Night ===== 01:54Z - Sunset. 01:58Z - Opened. Forced a fill and checked balance. My MJCI was not updating (it was running on my laptop), so I tried to "Refresh Info" and I received the following error: "Response : STATUS > transaction ERR: recvd NO reply." Dmitry's MJCI was working fine and we were still able to take data. I had to try the "Re-connect to All LCU Agents" button twice and then things were updating normally and I had the "DC agent response OK" back. Cart. 5, 3413A, HD88133, POST-SEL. ********************************** 02:24Z - gotoField. Used fk5 to acquire the field. Checked focus. 02:25Z - TIO. T02:25:41.760.fits 02:28Z - ThAr. T02:28:02.130.fits 02:34Z - TIO. T02:34:40.460.fits 02:48Z - SCIENCE. 50 min. T02:48:03.170.fits. = 39.36. Suspect spectra for 5 A include: (117,118) : Blue Clear Orange (113,114) : Blue Clear Magenta (077,078) : Blue Clear Yellow (073,074) : Blue Clear Cyan 03:40Z - TIO. T03:40:24.930.fits 03:43Z - ThAr. T03:43:23.800.fits 03:48Z - TIO. T03:48:08.830.fits Cart. 6, 3416B, HD89744, POST-SEL. ************************************** 03:34Z - gotoField. Used fk5 to acquire the field. 04:01Z - SCIENCE. 50 min. T04:01:55.990.fits. = 33.41. Suspect spectra for 6 B include: (023,024) : Green Green Yellow 04:55Z - TIO. T04:55:46.230.fits 04:58Z - ThAr. T04:58:18.570.fits 05:03Z - TIO. T05:03:24.830.fits Cart. 6, 3416A, HD89307, POST-SEL. ********************************** 04:54Z - gotoField. Used fk5 to acquire the field. 05:09Z - SCIENCE. 50 min. T05:09:37.680.fits. = 30.48. No suspect fibers. 05:50Z - I've noticed that my Watcher session has twice dropped its connection to the server and while it doesn't last long and establishes a connection relatively soon after dropping out, I thought it may be worth mentioning: watch> dropping server connection to sdsshost2.apo.nmsu.edu on port 30307 (server) connected: registered 06:00Z - tccPutAndWait timeout during instChange as the TCC never completed the slew to 121,90,00, or so it thought. Details in Problems section. 06:06Z - TIO. T06:06:16.700.fits 06:08Z - ThAr. T06:08:45.940.fits 06:13Z - TIO. T06:13:56.270.fits Cart. 3, 3277B, GJ436, POST-SEL. ******************************** 06:07Z - gotoField. We had some trouble finding the field (only 3 guide stars for this one) and then the fk5 for this field. To begin with, guider images were very slow showing up in SAOImage (~25 seconds went by the time they showed up after TCCMon showed the gcam exposure time finished). Jon killed the mcptpm-logs gzip process and this increased refresh rates, but we still had problems finding the fk5. We had correctly loaded the cartridge, plate, and pointing, and the fiducials looked fine. We decided to cross fiducials anyway since everything else we could think of was in spec. The altitude axis immediately complained of a large fiducial offset, so even though the murmur log showed no problems with the most recent altitude fiducial crossing, it must have gained a large offset after that crossing. After we forced the altitude fiducial we were able to find the fk5. 06:40Z - I noticed in the murmur log "Ignoring errors for sp1 as instrument's down (as per cameraDown)" which doesn't seem to make any sense. We were not sure why sp1 would be down, nor was Jon, but we brought it back up. sp1> cameraDown sp1 -show sp1 is down sp1> cameraDown sp2 -show sp2 is up sp1> cameraDown sp1 -up sp1> cameraDown sp1 -show sp1 is up 07:06Z - SCIENCE. 50 min. T07:06:08.980.fits. = 27.16. No suspect fibers. 07:58Z - At the telescope laptop, I moved the track ball to clear the screen saver and not quite a second after it cleared, all the windows disappeared and the login-to-sdsshost2 window came up, so all that was left to do was to restart the software on the laptop. 07:59Z - TIO. T07:59:02.240.fits 08:03Z - ThAr. T08:03:00.270.fits 08:07Z - TIO. T08:07:36.110.fits Cart. 8, 3359B, K15, POST-SEL. ****************************** 08:05Z - gotoField. Used fk5 to acquire the field. 08:16Z - SCIENCE. 50 min. T08:16:03.730.fits. = 52.90. No suspect fibers. 09:08Z - TIO. T09:08:00.020.fits 09:10Z - ThAr. T09:10:53.570.fits 09:15Z - TIO. T09:15:35.060.fits Cart. 7, 3489B, KEPLER3.TRES-2, POST-SEL. ***************************************** 09:12Z - gotoField. GSOGTF. 09:20Z - The wind direction shifted and began blowing from the NE. As a result the dust began to spike (up to 3800, but the manual counter read 2800 on two tests), the temperature dropped, the humidity increased, and the seeing was awful to the extent that the guider was not recognizing the guide stars. We delayed beginning an exposure. 09:38Z - We checked windshields and determined that there was a yellow hue to the dust, so we closed immediately for pollen; it came hard and it came really fast. 10:15Z - endNight finished manually. ---=== 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 ===--- Summary Checked (y/n): Y QA Procedures Done (y/n): Y UT Exp Time flavor comment (S/N)^2 totals ========================================== b1 r1 b2 r2 ----- sequence 61059, plate -9999 ------- 01:36 61059 0.0 bias 01:51 61060 0.0 bias MARVELS Exposure Name Flavor Exp. Time ========================================================================= MARVELS1.2009-05-09T02:25:41.760.fits TIO 15.000000 48076.800781 MARVELS1.2009-05-09T02:28:02.130.fits THAR 160.000000 178.268753 MARVELS1.2009-05-09T02:34:40.460.fits TIO 15.000000 48066.332031 MARVELS1.2009-05-09T02:48:03.170.fits STAR 3000.000000 39.355000 MARVELS1.2009-05-09T03:40:24.930.fits TIO 15.000000 47847.601562 MARVELS1.2009-05-09T03:43:23.800.fits THAR 160.000000 173.768753 MARVELS1.2009-05-09T03:48:08.830.fits TIO 15.000000 47693.066406 MARVELS1.2009-05-09T04:01:55.990.fits STAR 3000.000000 33.407665 MARVELS1.2009-05-09T04:55:46.230.fits TIO 15.000000 48314.933594 MARVELS1.2009-05-09T04:58:18.570.fits THAR 160.000000 178.918747 MARVELS1.2009-05-09T05:03:24.830.fits TIO 15.000000 47857.398438 MARVELS1.2009-05-09T05:09:37.680.fits STAR 3000.000000 30.481001 MARVELS1.2009-05-09T06:06:16.700.fits TIO 15.000000 47665.867188 MARVELS1.2009-05-09T06:08:45.940.fits THAR 160.000000 171.556244 MARVELS1.2009-05-09T06:13:56.270.fits TIO 15.000000 47573.332031 MARVELS1.2009-05-09T07:06:08.980.fits STAR 3000.000000 27.115334 MARVELS1.2009-05-09T07:59:02.240.fits TIO 15.000000 47768.535156 MARVELS1.2009-05-09T08:03:00.270.fits THAR 160.000000 174.712494 MARVELS1.2009-05-09T08:07:36.110.fits TIO 15.000000 47608.867188 MARVELS1.2009-05-09T08:16:03.730.fits STAR 3000.000000 52.901333 MARVELS1.2009-05-09T09:08:00.020.fits TIO 15.000000 46971.601562 MARVELS1.2009-05-09T09:10:53.570.fits THAR 160.000000 170.487503 MARVELS1.2009-05-09T09:15:35.060.fits TIO 15.000000 46601.667969 ---=== TELESCOPE OFFSETS AND SCALE I ===--- Time Instrument Az Alt Rot Scale pos offset pos offset pos offset ------------------------------------------------------------------------------ 02:58Z 5 3413 -42.30 -0.0032 71.09 0.0028 143.46 0.0022 1.000070 04:14Z 6 3416 241.82 0.0063 65.45 0.0045 79.62 0.0166 1.000070 05:57Z 6 3416 277.91 0.0016 35.20 0.0042 121.43 -0.0021 1.000100 07:07Z 3 3277 263.43 0.0036 44.46 0.0041 110.91 0.0151 1.000070 08:17Z 8 3359 120.47 0.0043 49.74 0.0090 -92.06 0.0126 1.000210 ---=== TELESCOPE OFFSETS AND SCALE II ===--- ---=== FOCUS LOG ===--- setmir piston Temp Wind Time Inst scale M1 M2 Foc Az Alt (C) MPH Dir filt fwhm ------------------------------------------------------------------------------ 02:58Z 5 3413 1.00007 -690 287 -270 -42 71.1 17.6 15 241 gdr. 1.4" 04:13Z 6 3416 1.00007 -690 397 -170 242 65.5 17.0 10 262 gdr. 1.3" 05:57Z 6 3416 1.00010 -986 317 -100 278 35.2 16.7 14 262 gdr. 1.4" 07:07Z 3 3277 1.00007 -690 527 -100 263 44.5 15.5 8 262 gdr. 1.2" 08:17Z 8 3359 1.00021 -2073 -635 -100 120 49.7 15.5 6 269 gdr. 1.1" ---=== WEATHER LOG ===--- Wind Time Temp F Dewp F MPH Direction Dust DIMM Sky 01:24Z 68 24 10 239 (WSW) 1495 - clear 01:58Z 64 20 14 229 (SW) 1552 - clear 02:32Z 63 19 12 235 (SW) 1568 - clear 03:03Z 63 19 10 235 (SW) 1548 - clear 03:34Z 63 19 8 275 (W) 1492 - clear 04:05Z 63 19 18 275 (W) 1610 - clear 04:35Z 62 17 9 268 (W) 1652 - clear 05:07Z 62 18 9 262 (W) 1670 - clear 05:37Z 61 18 9 263 (W) 1758 - clear 06:10Z 62 17 11 265 (W) 1734 - clear 06:44Z 61 17 9 264 (W) 1868 - clear 07:17Z 59 17 6 263 (W) 1780 - clear 07:47Z 59 17 5 260 (W) 1776 - clear 08:18Z 59 17 5 269 (W) 1710 - clear 08:50Z 59 17 3 298 (WNW) 1752 - clear 09:21Z 50 32 12 82 (E) 2785 - clear 09:52Z 48 41 13 70 (ENE) 4131 - clear ---=== TELESCOPE STATUS ===--- 01:25Z - Began ventilation. Doors and louvers opened, fans on. 01:58Z - Enclosure off. 09:38Z - Enclosure on, doors and louvers closed, fans off. No interlocks bypassed. Status at: 10:16Z Telescope stowed at: 30,121,00 mount Instrument mounted: Cartridge 7 Counterweights at: 258 lbs LN2 autofill systems: Connected and turned on. 180L LN2 dewar scales: Spectro 138.10 lbs, 17.79 psi Imager N/A lbs, N/A psi ---=== SOFTWARE USED ===--- IOP/SOP: v4_39_0 Watcher: v2_36_0 MCP: v6_6_0 TPM: tpm_v3_5_0 AstroDa: v15_13_1 TCC: TCC 2.10.0 2009-01-12 sdssProcedures: v2_43 SoS: v5_1_8 plate-mapper: v4_3_1 MJCI: version 2009/05/05 MJDD: version 2009/05/05 ---=== MIRROR NUMBERS ===--- PRIMARY: -------- Scale: 1.000000 MIGS TONIGHT NOMINAL Axial A -0.0250 -0.0280 Axial B 0.0320 0.0470 Axial C -0.0280 -0.0360 Trans D -0.7550 -0.7600 Lateral E 10.5791 10.5791 Lateral F 12.1793 12.1793 GALILS Commanded: 10450. -100. 5750. 8600. 10350. 10000. Actual: 10471. -76. 5755. 8616. 10374. 10023. SETMIR VALUES PriDesOrient: 0.00 -11.72 8.60 496.70 640.50 PriOrient: 1.06 -11.65 8.77 495.77 639.59 SECONDARY: ---------- Focus: 0.00 Air Temp.: 19.8 Alt.: 29.999997 MIGS TONIGHT NOMINAL Axial A 18.5860 18.5840 Axial B 15.6310 15.6220 Axial C 13.8080 13.8150 Trans D 15.1010 15.1080 GALILS Commanded: 1627044. 1528922. 1595491. -2950. -4550. Actual: 1626650. 1528800. 1595600. -2950. -4550. SETMIR VALUES SecDesOrient: 1257.00 -12.00 -28.00 -39.00 94.77 SecOrient: 1257.12 -11.89 -28.12 -39.26 94.63 ---=== PROBLEMS IN DETAIL ===--- Spectro Bias ------------ IDL 5.5a> apo_plotbias, 61059 Filename 02% 05% 10% 50% 90% 95% 98% ------------------- ------ ------ ------ ------ ------ ------ ------ sdR-b1-00061059.fit -5.8 -4.3 -2.5 2.0 7.4 9.3 10.7 sdR-b2-00061059.fit -8.0 -5.8 -4.3 1.7 8.0 9.2 10.6 sdR-r1-00061059.fit -6.5 -4.6 -3.2 2.2 7.7 9.8 12.0 sdR-r2-00061059.fit -7.7 -5.6 -3.6 1.7 8.0 10.1 12.2 TCC Timeout ----------- 05:59:43Z - stopGuider. 06:00:46Z - instChange issued. Immediately after instChange was issued, the murmur log began showing: [doravetz@sdsshost2 astrolog]$ less iop.murmur.log | grep 06:00:4 | grep IOP | grep -i tcc 2009-05-09 06:00:47Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:00:48Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC These showed up every second it seemed, until: [doravetz@sdsshost2 astrolog]$ less iop.murmur.log | grep 06:04 | grep IOP | grep -i tcc 2009-05-09 06:04:00Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:01Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:02Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:03Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:04Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:05Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:06Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:07Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:08Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:09Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:10Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:11Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:12Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:13Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:14Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:15Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:16Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:17Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:18Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait finished trying listenerToTCC 2009-05-09 06:04:18Z sdsshost2 IOP 10195 TEXTONLY tccPutAndWait timed out waiting for the TCC to complete command track 121,90 mount /rotangle=0 /rottype=mount 2009-05-09 06:04:20Z sdsshost2 IOP 10195 TEXTONLY Stopping listenerToTCC 2009-05-09 06:04:20Z sdsshost2 IOP 10195 TEXTONLY Can not find tccHandler in the event loop, so can not delete it 2009-05-09 06:04:20Z sdsshost2 IOP 10195 TEXTONLY Stopping tccHandler This was what SOP had to say after the tccPutAndWait timeout: timed out waiting for the TCC to complete command track 121,90 mount /rotangle=0 /rottype=mount while executing "error $errorMessage" invoked from within "if {[getclock] > $startTime + $timeout} { set errorMessage "timed out waiting for the TCC to complete command $tccCommand" murmur "tccPutAndWait ..." invoked from within "if {!$TCCCommandComplete($commandIndex)} { if {[getclock] > $startTime + $timeout} { set errorMessage "timed out waiting for the TCC to comple ..." ("while" body line 4) invoked from within "while {!$TCCCommandComplete($commandIndex)} { listenerToTCC murmur "tccPutAndWait finished trying listenerToTCC" if {!$TCCCommandComplete($c ..." (procedure "tccPutAndWait" line 17) invoked from within "tccPutAndWait "track 121,90 mount /rotangle=$rot_dest /rottype=mount"" (procedure "instChange" line 109) invoked from within "instChange -noInit" ("eval" body line 1) invoked from within "eval "instChange $option"" (procedure "GUIinstChange" line 41) invoked from within "GUIinstChange $GUIinstChangeOption" invoked from within ".sgui.instchange.go invoke" ("uplevel" body line 1) invoked from within "uplevel #0 [list $w invoke]" invoked from within "if {($w == $tkPriv(window)) && ([$w cget -state] != "disabled")} { uplevel #0 [list $w invoke] }" invoked from within "if {$w == $tkPriv(buttonWindow)} { set tkPriv(buttonWindow) "" $w config -relief $tkPriv(relief) if {($w == $tkPriv(window)) && ([$w cget -state] ..." (procedure "tkButtonUp" line 3) invoked from within "tkButtonUp .sgui.instchange.go" (command bound to event) The MCP appeared to be working, but the slithead doors were opened and slithead latches retracted at the same time that instChange was issued: [doravetz@sdsshost2 astrolog]$ less iop.murmur.log | grep 06:00 | grep IOP | grep -i slit 2009-05-09 06:00:46Z sdsshost2 IOP 10195 TEXTONLY instChange: opening slithead doors 2009-05-09 06:00:46Z sdsshost2 IOP 10195 TEXTONLY instChange: retracting slithead latches The MCP information was refreshing normally during the slew to instChange and throughout the TCC hang-up, but we did not issues any commands through the MCP while we were waiting for instChange. SOP was frozen while the TCC was trying to complete the slew to 121,90,00 as a result of tccPutAndWait. SOP and SOPGUI won't allow us to do anything during the instChange procedure even when the TCC does not hang. After instChange has finished, then we get the SOP prompt back and can access SOPGUI. So, as long as the TCC doesn't complete the slew to instChange, SOP won't be available. sp1> tccPutAndWait -help "Send a command to the TCC, and do not return until the TCC reports that the command has completed. Note that the default timeout time is very long, to allow for long slews." The TCC was hung insofar as it never completed the slew to 121,90,00 and as a result tccPutAndWait timed out.