APACHE POINT OBSERVATORY SDSS 2.5M OBSERVING LOG Saturday February 16, 2008 (MJD 54513) ---=== OBSERVING TEAM ===--- Dmitry Bizyaev Viktor Malanushenko swatters (afternoon) Dan Long (by phone) Jon Brinkmann (by phone) ---=== OBSERVING PLAN ===--- Science! ---=== OBSERVING SUMMARY ===--- Problems with sp1 in the evening (see 'log' and 'problems' sections). High humidity, then blowing snow. We never opened, sorry. ---=== OBSERVING LOG ===--- Afternoon: --------- All systems checked. After taking the initial spectro bias and then trying a postCal sop kept complaining about an "ongoing exposure on sp1". After forcing it to endStare, exiting sop sessions, and making sure the ports were available, an attempt to take a bias was tried with the same error. Rebooting the spectro crate, exiting sop sessions, etc, and trying a bias resulted in the same error. After talking to Dan Long we power cycled the sp1 black box on the telescope and were able to take a bias. Night: ----- The next chain of events and summary of the problem see in the Problems section. High humidity, then blowing snow. We never opened, sorry. 11:50 endNight rejoiced and finished, but the next files did not included: 50073,50074,50075,50076,50077 (supposely, due to the evening problem with sp1, see the 'problems' section).These are precal and collimation files, all have the "test" flag. ---=== IMAGING RUN SUMMARY ===--- Run Time Stripe Lambda Last Flavor Comments Start End Begin End Frame ------------------------------------------------------------------------- 7328 22:32Z 22:55Z 100 O -166.60 -160.82 53 ignore ---=== 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): QA Procedures Done (y/n): UT Exp Time flavor comment (S/N)^2 totals ========================================== b1 r1 b2 r2 ----- sequence 50052, plate -9999 ------- 22:32 50052 0.0 bias ----- sequence 50053, plate 2939 ------- 23:02 50053 3.0 arc ---=== TELESCOPE OFFSETS AND SCALE I ===--- Time Instrument Az Alt Rot Scale pos offset pos offset pos offset ------------------------------------------------------------------------------ ---=== TELESCOPE OFFSETS AND SCALE II ===--- ---=== FOCUS LOG ===--- setmir piston Temp Wind Time Inst scale M1 M2 Foc Az Alt (C) MPH Dir filt fwhm ------------------------------------------------------------------------------ ---=== WEATHER LOG ===--- Wind Time Temp F Dewp F MPH Direction Dust DIMM Sky 21:22Z 25 21 12 314 (NW) 1202 - 21:59Z 26 21 11 333 (NNW) 1455 - 22:30Z 27 23 16 302 (WNW) 2537 - 23:00Z 28 24 10 322 (NW) 3078 - 23:31Z 28 24 18 286 (WNW) 2892 - 00:01Z 29 26 15 304 (NW) 4517 - 01:44Z 29 26 18 295 (WNW) 430 - 02:16Z 28 26 10 285 (WNW) 437 - 02:46Z 28 26 12 285 (WNW) 450 - 02:54Z 28 26 7 281 (W) 460 - 03:26Z 28 25 10 301 (WNW) 519 - 03:58Z 28 24 10 291 (WNW) 524 - 04:22Z 28 24 12 287 (WNW) 554 - 04:55Z 27 23 12 316 (NW) 498 - 05:27Z 26 23 8 339 (NNW) 491 - 05:59Z 25 22 17 317 (NW) 493 - 06:31Z 24 20 11 0 (N) 414 - 07:03Z 24 19 21 4 (N) 443 - 07:35Z 25 18 16 24 (NNE) 597 - 08:08Z 25 17 22 22 (NNE) 627 - 08:40Z 25 17 24 28 (NNE) 660 - 09:12Z 25 17 13 15 (NNE) 685 - 09:44Z 26 16 13 24 (NNE) 683 - 10:16Z 26 14 26 6 (N) 713 - 10:48Z 25 15 16 15 (NNE) 677 - 11:21Z 25 15 22 16 (NNE) 665 - 11:53Z 26 15 21 3 (N) 643 - ---=== TELESCOPE STATUS ===--- We didn't open. Status at 12:00 Telescope stowed at: 30,121,00 mount Instrument mounted: Cartridge 4 Counterweights at: 270 lbs LN2 autofill systems: Connected and turned on. 180L LN2 dewar scales: Spectro 127.3 lbs, 18.8 psi Imager 201.3 lbs, 23.2 psi ---=== SOFTWARE USED ===--- IOP/SOP: v4_38_0 Watcher: v2_36_0 MCP: v6_4_0 TPM: tpm_v3_5_0 AstroDa: v15_13_1 TCC: TCC 2.7.2.1 August 6 2004 sdssProcedures: v2_38 SoS: v5_1_8 plate-mapper: v4_3_1 ---=== MIRROR NUMBERS ===--- PRIMARY: -------- Scale: 1.000000 MIGS TONIGHT NOMINAL Axial A -5.2140 -5.2160 Axial B -0.2140 -0.2142 Axial C -0.0014 -0.0016 Trans D 11.8410 11.8540 Lateral E 10.0711 10.0584 Lateral F 11.6586 11.6586 GALILS Commanded: 4600. -2000. 2650. -12450. -6500. -6550. Actual: 4600. -2000. 2650. -12439. -6477. -6546. SETMIR VALUES PriDesOrient: 0.00 0.00 0.00 100.00 -200.00 PriOrient: 0.00 0.00 0.00 99.59 -200.69 SECONDARY: ---------- Focus: 0.00 Air Temp.: -2.4 Alt.: 30.000712 MIGS TONIGHT NOMINAL Axial A 0.8027 0.8025 Axial B 0.6124 0.6120 Axial C 0.5475 0.5474 Trans D 0.6168 0.6008 GALILS Commanded: 1627479. 1653142. 1470818. -5900. -7800. Actual: 1627496. 1653168. 1470885. -5887. -7780. SETMIR VALUES SecDesOrient: 1257.00 60.00 -4.00 -20.00 118.90 SecOrient: 1256.97 60.02 -4.01 -19.92 119.27 ---=== PROBLEMS IN DETAIL ===--- Spectro Focus (using cart 4): ---------------------------- No adjustment. Focus should still be set to ~2C. sp1> mechSend s spMechVersion v2_9_0 Bootup 870616738 SpectroID 1 SlitID 36 Air On Shutter_open_sensor Off Shutter_closed_sensor On Left_open_sensor Off Left_closed_sensor On Right_open_sensor Off Right_closed_sensor On Coll_motor_A 0 01P0000000000 Coll_motor_B 0 02P0000000000 Coll_motor_C 0 01P0000000000 Coll_motor_A_status 133 01S0133 Coll_motor_B_status 133 02S0133 Coll_motor_C_status 133 01S0133 Requested_exp.time 0 Exp_time_left 0 Last_exp.time 0 Last_open_transit.time 0 Last_close_transit.time 0 Humid_Hartmann 28.8 0xFD3C Humid_Cen_Optics 14.9 0xFDF3 Temp_Median 4.3 Temp_Hartmann_Top 2.9 (0xFF85) Temp_Red_Cam_Bot 4.0 (0xFF58) Temp_Red_Cam_Top 4.7 (0xFF3C) Temp_Blue_Cam_Bot 4.3 (0xFF4C) Temp_Blue_Cam_Top 4.3 (0xFF4C) AD 13951 1294 ---------------------------- Collimate: IDL 5.5a> collimate, 50076 % Compiled module: COLLIMATE. Reading /data/spectro/54513/sdR-b1-00050076.fit Reading /data/spectro/54513/sdR-b1-00050077.fit COLLIMATE: Min offset = -0.95 pix COLLIMATE: Max offset = 0.87 pix COLL COLLIMATE: Mean offset = -0.02 pix COLLIMATE: Camera b1 appears to be IN-FOCUS (|mean| < 0.15 pix) COLLIMATE: Predict blue camera ring movement of 0.6 degrees for spectro-1 COLLIMATE: (if red is already in focus) Log file = Collimate-54513-b1-00050076.log PostScript file = Collimate-54513-b1-00050076.ps Reading /data/spectro/54513/sdR-b2-00050076.fit Reading /data/spectro/54513/sdR-b2-00050077.fit COLLIMATE: Min offset = -0.26 pix COLLIMATE: Max offset = 0.15 pix COLLIMATE: RMS across CCD = 0.09 pix COLLIMATE: Mean offset = -0.01 pix COLLIMATE: Camera b2 appears to be IN-FOCUS (|mean| < 0.15 pix) COLLIMATE: Predict blue camera ring movement of 0.5 degrees for spectro-2 COLLIMATE: (if red is already in focus) Log file = Collimate-54513-b2-00050076.log PostScript file = Collimate-54513-b2-00050076.ps Reading /data/spectro/54513/sdR-r1-00050076.fit Reading /data/spectro/54513/sdR-r1-00050077.fit COLLIMATE: Min offset = -0.79 pix COLLIMATE: Max offset = 0.21 pix COLLIMATE: RMS across CCD = 0.28 pix COLLIMATE: Mean offset = -0.33 pix COLLIMATE: Camera r1 appears to be OUT-OF-FOCUS (|mean| > 0.15 pix) COLLIMATE: Predict (red) piston movement of 2982 steps for spectro-1 COLLIMATE: Issue SOP command: "sp1; mechPiston 2982" Log file = Collimate-54513-r1-00050076.log PostScript file = Collimate-54513-r1-00050076.ps Reading /data/spectro/54513/sdR-r2-00050076.fit Reading /data/spectro/54513/sdR-r2-00050077.fit COLLIMATE: Min offset = -0.72 pix COLLIMATE: Max offset = 0.13 pix COLLIMATE: RMS across CCD = 0.22 pix COLLIMATE: Mean offset = -0.11 pix COLLIMATE: Camera r2 appears to be IN-FOCUS (|mean| < 0.15 pix) COLLIMATE: Predict (red) piston movement of 969 steps for spectro-2 COLLIMATE: Issue SOP command: "sp2; mechPiston 969" Log file = Collimate-54513-r2-00050076.log PostScript file = Collimate-54513-r2-00050076.ps =============================== Evening problem with sp1. OK, we took bias, but then exposure failed again during precals. Next attempts to take any kind of exposure from any workplace brought the same message that "There is an ongoing exposure on sp1". A typical sequence of errors was like this: ***************************************** WARNING: SOP and the DA have conflicting records of the current frame number. SOP's value: 50062 DA's value: 50064 You can: 1. Type "1" to have goStare set both to 50064 and continue 2. Type "2" to abort goStare and fix it yourself goStare> 1 2008-02-17 00:03:50Z: There is an ongoing exposure on sp1. Error: There is an ongoing exposure on sp1 We tried "endStare -force". The exposure was read from sp1 only, and gave an unusual picture at sp1 monitor, just 2/3 was occupied by image, it had a time stamp. The endStare didn't fix the problem and next attempts to start bias or calibration frame ended with the message about ongoing exposure. No locked ports found. What we have done after that (and what didn't help): -logged out all sop sessions, logged in again; -rebooted spectro crate; -noticed that there are 9 zombi processes at sdsshost2. The very prominent was a tcsh session from "observer" started ~2 days ago from pts/4. We were unable to kill it from observer, and then from root account! It was unusual and we decided to reboot sdsshost2. we did it , restored everything and tried a bias again. The same "ongoing exposure" at sp1. Following advise of Dan Long, we power cycled the black box on sp1. It helped! and we took bias well. Once we tried to check a postcal, it again started claiming about ongoing exposure on sp1. Second time we went to the box on sp1, we noticed indication that readout fails and that "shutter timeout". We power cycled it again and the story repeated, i.e. finally we came to the same "ongoing exposure". Then we noticed that the file /data/spectro/54513/frames.list contains a lot (~7130) entries with weird fits-file names: there were spaces instead of b1,b2,r1,r2 in the file names. The directory itself contained just the first two exposure files that Shannon took before the problem bloomed up. At the same time, the pool contained some untransferred files, and "teamster" didn't start their transfer. Then we copy the frames.list to frames.list.OLD, cleaned the file frames.list of bad lines, cleaned the pool space, and restarted the teamster. After that we reseted the sp1 box again, and went ahead and took bias. It's not over yeat, keep tuned. During the bias taking we got: sp1> IOP running as Backup Relay Server requestListen: listening 2 2008-02-17 01:56:00Z 3 sp1 camcheck 2008-02-17 01:56:02Z 3 sp1 mechstat mechstat: Cannot get good values from mechanicals: return value was s spMechVersion v2_9_0 Bootup 870616738 SpectroID 1 SlitID 36 Air On Shutter_open_sensor Off Shutter_closed_sensor On Left_open_sensor Off Left_closed_sensor On Right_open_sensor Off Right_closed_sensor On Coll_motor_A 0 01P0000000000 Coll_motor_B 0 02P0000000000 Coll_motor_C 0 01P0000000000 ... i.e. mechstat was unable to connect to sp1, and instead of taking bias, it spitted out information that usually mechSend gives out. We decided to reset sp1 box again, and, oh wonder, it showed it is connected and allowed to take bias. Then we successfully took postcal and collimation frames. We think a combination of problems came to us. It was initialized by sp1 mechanical failure (in turn the reason might be in high humidity and pretty low temperature ~ -6C caused snow and thick fog), then a lot of wrong lines came to the frames list and clogged teamster and probably some more scripts around data transferring and file name registration. Mechanical guts of sp1 need to be checked. We didn't lost useful time due to this problem because of high humidity and thick fog on site in the evening/beginning of night. We notified Dan Long, Jon called as well.