APACHE POINT OBSERVATORY SDSS 2.5M OBSERVING LOG Tuesday September 6, 2005 (MJD 53620) ---=== OBSERVING TEAM ===--- swing: Jurek night: Steph Snedden Howard Brewington Kaike Pan Jon Brinkmann (phone) Eric Neilsen (phone support) ---=== OBSERVING PLAN ===--- Science! ---=== OBSERVING SUMMARY ===--- Because of high humidity and rain, we never opened. We worked with Eric to preform memory tests. We tried to do imager cals but discovered that the stage encoder was not working properly; see log. ---=== OBSERVING LOG ===--- Afternoon checkout: ------------------- Imager bias drift fine, spectro bias ok., guider checked, spectrographs in focus. xmax was corrected (see the problem section). No problem this afternoon. Telescope ready for tonight. At afternoon checkout, we noticed that requested check on the chiller guage (pressure showing 22, nominal label is 28) was not answered during the day. The same with N2 (red) bottle presure ~500 psi. Night: ------ During the early evening, we talked with Jon Brinkmann about the chiller, and he said that the lower pressure is a result of worked preformed during the summer shutdown. Consequently, the reading of ~22 is now the "new" normal for this time of year and that a old normal-pressure label on that gauge should be replaced. But, he warned that the pressure will rise during the colder winter months. John also said that Norm was aware of the ~500 psi of the N2 bottles in the lower enclosures. We had rain and high humidity at sunset, so we waited for better conditions. In the mean time, we did Eric's memory leak tests/checks and tried doing imager cals. We started testing memory usage for Eric with astrom. A new astrom session had these allocations: astrom> memStatsPrint Number of memory allocation requests:     15 Number of memory de-allocation requests:  15 Total bytes currently in use:             0 Total bytes in Free Memory Pool:          448 Total bytes allocated by malloc():        728 Percentage of memory allocation requests   satisfied from Free Memory Pool:        53.33 % Percentage of memory allocation requests   satisfied from the Operating System:    46.67 % We ran a skippy which failed with: astrom> skippy 5565 15 3 -mjd 53616  ERROR: oldAstrom: oldAstrom: tunable parameter 'magDiff' missing from tunable pa rameters file NONE oldAstrom: tunable parameter 'magDiff' missing from tunable parameters file     while executing "error "oldAstrom: tunable parameter '$param' missing from tunable parameters fi le"" The new allocations after this failure: astrom> memStatsPrint                 Number of memory allocation requests:     145 Number of memory de-allocation requests:  140 Total bytes currently in use:             40060 Total bytes in Free Memory Pool:          51200 Total bytes allocated by malloc():        10574720 Percentage of memory allocation requests   satisfied from Free Memory Pool:        17.24 % Percentage of memory allocation requests   satisfied from the Operating System:    82.76 % The same skippy command was run again, and the new allocations were: astrom> memStatsPrint                Number of memory allocation requests:     270 Number of memory de-allocation requests:  262 Total bytes currently in use:             60108 Total bytes in Free Memory Pool:          51072 Total bytes allocated by malloc():        10574720 Percentage of memory allocation requests   satisfied from Free Memory Pool:        55.19 % Percentage of memory allocation requests   satisfied from the Operating System:    44.81 % Eric thinks this is not the source of the memory problem. He next moved on to MOP The two MOPs (command line and GUI gave the following) Memory usagge by command line MOP: mt> memStatsPrint Number of memory allocation requests:     4193 Number of memory de-allocation requests:  78 Total bytes currently in use:             165368 Total bytes in Free Memory Pool:          0 Total bytes allocated by malloc():        436600 Percentage of memory allocation requests   satisfied from Free Memory Pool:        1.86  % Percentage of memory allocation requests   satisfied from the Operating System:    98.14 % To get memory usage by MOP GUI, specifically: mt> send $mopGUI(GUIMOPwindow) memStatsPrint Number of memory allocation requests:     4978 Number of memory de-allocation requests:  79 Total bytes currently in use:             196726 Total bytes in Free Memory Pool:          64 Total bytes allocated by malloc():        518304 Percentage of memory allocation requests   satisfied from Free Memory Pool:        1.57  % Percentage of memory allocation requests   satisfied from the Operating System:    98.43 % Memory Usage by SOP before 5 guider images taken: sp1> memStatsPrint Number of memory allocation requests:     20729 Number of memory de-allocation requests:  19370 Total bytes currently in use:             326334 Total bytes in Free Memory Pool:          72586920 Total bytes allocated by malloc():        73046688 Percentage of memory allocation requests   satisfied from Free Memory Pool:        87.64 % Percentage of memory allocation requests   satisfied from the Operating System:    12.36 % And after 5 guder images: sp1> SOPGUI: gcam 1.0 SOPGUI: gcam 1.0 SOPGUI: gcam 1.0 SOPGUI: gcam 1.0 SOPGUI: gcam 1.0 sp1> memStatsPrint Number of memory allocation requests:     23645 Number of memory de-allocation requests:  21436 Total bytes currently in use:             621830 Total bytes in Free Memory Pool:          72041328 Total bytes allocated by malloc():        73111568 Percentage of memory allocation requests   satisfied from Free Memory Pool:        87.17 % Percentage of memory allocation requests   satisfied from the Operating System:    12.83 % Memory usage by IOP before a bias drift: im> memStatsPrint Number of memory allocation requests:     201 Number of memory de-allocation requests:  200 Total bytes currently in use:             304 Total bytes in Free Memory Pool:          64 Total bytes allocated by malloc():        656 Percentage of memory allocation requests   satisfied from Free Memory Pool:        99.00 % Percentage of memory allocation requests   satisfied from the Operating System:    1.00  % And after the drift: im> memStatsPrint  Number of memory allocation requests:     691 Number of memory de-allocation requests:  272 Total bytes currently in use:             9880 Total bytes in Free Memory Pool:          960 Total bytes allocated by malloc():        47888 Percentage of memory allocation requests   satisfied from Free Memory Pool:        37.19 % Percentage of memory allocation requests   satisfied from the Operating System:    62.81 % Next we ran more tests on MOP. The initial memory status: mt> memStatsPrint                             Number of memory allocation requests:     4406 Number of memory de-allocation requests:  291 Total bytes currently in use:             165368 Total bytes in Free Memory Pool:          1919145152 Total bytes allocated by malloc():        1919587832 Percentage of memory allocation requests   satisfied from Free Memory Pool:        3.15  % Percentage of memory allocation requests   satisfied from the Operating System:    96.85 % Then a checkFocus was run, which failed: mt> checkFocus 267534 -mjd 53616 Sky level: 17.5217, sigma: 2.422437 Fatal error: DERVISH internal error(1): out of system memory mt>  mt> memStatsPrint                 Number of memory allocation requests:     4549 Number of memory de-allocation requests:  321 Total bytes currently in use:             658903692 Total bytes in Free Memory Pool:          1910270624 Total bytes allocated by malloc():        -1075599288 Percentage of memory allocation requests   satisfied from Free Memory Pool:        6.18  % Percentage of memory allocation requests   satisfied from the Operating System:    93.82 % A new MOP session was started with low mem usage: mt> memStatsPrint   Number of memory allocation requests:     76 Number of memory de-allocation requests:  75 Total bytes currently in use:             304 Total bytes in Free Memory Pool:          64 Total bytes allocated by malloc():        656 Percentage of memory allocation requests   satisfied from Free Memory Pool:        97.37 % Percentage of memory allocation requests   satisfied from the Operating System:    2.63  % From the new MOP, we did several checkFocus until the memory error occurred agai n, but the message was different: mt> checkFocus 267547 -mjd 53616 Sky level: 15.8107, sigma: 2.351035 Fatal error: Attempt to allocate 3452251808d == -842715488 bytes We ran a few more tests, making sure that saoDisplay used the right amount of me mory (a PT frame size) and it did. Eric concluded that there was some work to do  with how dervish and MOP handle memory. ++++++++++++++++++++++++++++++++++++++++++++ Next, we tried imager cals but discovered that the stage encoder was not reading properly. As indicated in the setup instructions, we set the encoder and stage at zero. And since an R-chip was in our plans, we tried advancing the stage via the mechanical crank to a setting of 14650 on the encoder. After moving the stage about fifty-percent of its movement, unfortunately, the encoder was only reading about 600. A PR was filed. endNight finished and was happy. ---=== IMAGING RUN SUMMARY ===--- Run Time Stripe Lambda Last Flavor Comments Start End Begin End Frame ------------------------------------------------------------------------- 5571 21:06Z 21:25Z 100 O 11.75 16.63 47 ignore 5573 03:51Z 03:57Z 100 O 113.24 114.89 25 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): y QA Procedures Done (y/n): y UT Exp Time flavor comment (S/N)^2 totals ========================================== b1 r1 b2 r2 ----- sequence 33868, plate -9999 ------- 21:29 33868 0.0 bias ----- sequence 33869, plate 2260 ------- 22:14 33869 0.0 bias 22:21 33870 10.0 flat 22:24 33871 2.0 arc 22:27 33872 2.1 arc 22:29 33873 2.1 arc 22:46 33874 10.0 flat 22:50 33875 2.0 arc 23:01 33876 2.1 arc 23:04 33877 2.1 arc ---=== TELESCOPE OFFSETS AND SCALE I ===--- Time Instrument Az Alt Rot Scale pos offset pos offset pos offset ------------------------------------------------------------------------------ ---=== TELESCOPE OFFSETS AND SCALE II ===--- ---=== DATA TAPE SUMMARY ===--- Goes: JL Stays: JL ---=== FOCUS LOG ===--- setmir piston Temp Wind Time Inst scale M1 M2 Foc Az Alt (C) MPH Dir filt fwhm ------------------------------------------------------------------------------ 22:11Z 8 0 1.00000 0 1258 0 121 30.0 11.2 13 80 ---=== WEATHER LOG ===--- Wind Time Temp F Dewp F MPH Direction Dust DIMM Sky 21:15Z 55 53 9 127 (SE) -9999 - 21:47Z 53 53 15 80 (E) -9999 - 22:18Z 52 50 21 69 (ENE) -9999 - 22:50Z 51 51 20 71 (ENE) -9999 - 23:20Z 52 52 14 62 (ENE) -9999 - 00:54Z 52 52 13 73 (ENE) -9999 - 01:27Z 52 51 12 82 (E) -9999 - 01:59Z 52 51 10 107 (ESE) -9999 - 02:31Z 52 51 7 86 (E) -9999 - 03:03Z 52 52 9 90 (E) -9999 - 03:35Z 52 52 10 108 (ESE) -9999 - 04:06Z 52 52 12 107 (ESE) -9999 - 04:37Z 52 52 12 110 (ESE) -9999 - 05:09Z 52 52 13 112 (ESE) -9999 - 05:42Z 51 51 13 107 (ESE) -9999 - 06:14Z 52 51 12 116 (ESE) -9999 - 06:46Z 52 50 12 114 (ESE) -9999 - 07:18Z 52 50 16 128 (SE) -9999 - 07:50Z 52 50 12 135 (SE) -9999 - 08:22Z 52 50 15 137 (SE) -9999 - 08:55Z 52 51 15 133 (SE) -9999 - 09:27Z 52 49 15 131 (SE) -9999 - 09:59Z 52 48 17 129 (SE) -9999 - 10:31Z 52 48 17 144 (SE) -9999 - ---=== TELESCOPE STATUS ===--- Telescope at 121,30,00 mount with cart 08 mounted. LN2 is connected and turned on. Spectro 185 lbs 24 psi Imager 216 lbs 21 psi ---=== SOFTWARE USED ===--- IOP/SOP: iop Watcher: watcher MCP: v5_26_0 TPM: tpm_v3_0_0 AstroDa: biery TCC: TCC 2.7.2.1 August 6 2004 sdssProcedures: SoS: hoggPT: v1_6_9 plate-mapper: ---=== MIRROR NUMBERS ===--- PRIMARY: -------- Scale: 1.000000 MIGS TONIGHT NOMINAL Axial A -5.8430 -5.8440 Axial B -5.6770 -5.6770 Axial C 0.9420 0.9420 Trans D -9.9940 -9.9940 Lateral E 10.3759 10.3759 Lateral F 11.9380 11.9380 GALILS Commanded: 4700. -2450. 3000. -7800. 3300. 3000. Actual: 4711. -2457. 2997. -7825. 3296. 3024. SETMIR VALUES PriDesOrient: 0.00 -1.68 7.05 385.25 92.02 PriOrient: 0.00 -1.52 7.02 384.99 93.81 SECONDARY: ---------- Focus: 0.00 Air Temp.: 11.3 Alt.: 30.000296 MIGS TONIGHT NOMINAL Axial A 1.5410 1.5420 Axial B 1.0460 1.0470 Axial C 1.1660 1.1650 Trans D -0.1100 -0.1240 GALILS Commanded: 1593438. 1603542. 1554232. -6800. -5900. Actual: 1593447. 1603642. 1554316. -6820. -5882. SETMIR VALUES SecDesOrient: 1257.00 15.87 0.00 -50.00 136.76 SecOrient: 1256.95 15.87 -0.03 -49.58 136.73 ---=== PROBLEMS IN DETAIL ===--- Check on the spectrograph collimation: -------------------------------------- sp2 Coll_motor_A 4810 Coll_motor_B 1780 Coll_motor_C 3310 xmax for r1 and r2 was shown in yellow: 2050.8 , 2062.4. The correction was made: sp1> mechMoveColl 350 350 -350 sp2> mechMoveColl 500 500 -500 after the correction, we have: sp1 Coll_motor_A -3178 Coll_motor_B -3178 Coll_motor_C -2678 sp2 oll_motor_A 5310 Coll_motor_B 2280 Coll_motor_C 2809 Spectrographs in focus.