Date: Sun, 13 Feb 2000 09:54:54 -0700 From: "s. a. snedden" Subject: 2.5-meter Obs Log (MJD 51587) SATURDAY FEBRUARY 12, 2000 (MJD 51587) APACHE POINT OBSERVATORY SDSS 2.5m OBSERVING LOG Observing team: Jeffrey Hayes (early) (APO) Scot Kleinman (middle) (APO) Atsuko Kleinman (middle) (APO) Stephanie Snedden (late) (APO) Bing Chen (PT) (JHU) Visitors: Steve Kent (FNAL) John Peoples (FNAL) The plan: Spectroscopy for the first half (FASTT field 317 and focal plane mapping), and if weather permits, imaging FASTT fields during the second half. We had the telescope ready to go by 19:00 (all check-outs and fiducials set). We waited on the weather. The wind was brisk: 25 mph steady and gusts to 35 mph. We took sample spectro guider and bias images with no problems. We started a camera bias drift and got the following messages on startup: im> goDrift -bias Sat Feb 12 19:08:52 MST 2000: No heartbeat found from ad1 in last 500 of murmur log Sat Feb 12 19:08:52 MST 2000: Sat Feb 12 19:08:52 MST 2000: Murmur not working for all ad1 node - Losing information!! Sat Feb 12 19:08:52 MST 2000: No heartbeat found from ad2 in last 500 of murmur log Sat Feb 12 19:08:52 MST 2000: Sat Feb 12 19:08:52 MST 2000: Murmur not working for all ad2 node - Losing information!! Sat Feb 12 19:08:52 MST 2000: No heartbeat found from ad3 in last 500 of murmur log Sat Feb 12 19:08:52 MST 2000: Sat Feb 12 19:08:52 MST 2000: Murmur not working for all ad3 node - Losing information!! Sat Feb 12 19:08:52 MST 2000: No heartbeat found from ad4 in last 500 of murmur log Sat Feb 12 19:08:52 MST 2000: Sat Feb 12 19:08:52 MST 2000: Murmur not working for all ad4 node - Losing information!! Sat Feb 12 19:09:17 MST 2000: Beginning data taking The drift started anyhow and the watcher didn't complain so we thought we'd go a bit and see if any other symptoms showed up. They did, but they do not appear related to the ad* problems. Shortly after the drift started, we got id2 error messages. We did an archPause and unloaded the id2 tapes. We issued an archUnload command, which did nothing but return and then unloaded the tapes by hand. Once this was done, we tried to reload them via: iccExec id2 archLoad 1 iccExec id2 archLoad 2 iccExec id2 archRewind 1 iccExec id2 archRewind 2 After the archRewind 2 command, we got the following error im> iccExec id2 archRewind 2 Error: {id2 {Task '%s' spawn failed}} which repeated for all subsequent id2-1 and id2-2 commands. So, we rebooted the crates and did an archLoad, archRewind, and archMount. Around this time, my imager server died. I was able to restart it ok, though. Once this was done, we did the following commands, with new tapes in id2: im> iccExec id2 archInit {id2 {}} im> iccExec id2 archLoad 1 {id2 {}} im> iccExec id2 archLoad 2 {id2 {}} im> iccExec id2 archRewind 1 {id2 {}} im> iccExec id2 archRewind 2 {id2 {}} im> iccExec id2 archRewind 2 {id2 {}} im> iccExec id2 archMount 1 2000 {id2 {}} im> iccExec id2 archMount 2 2000 {id2 {}} im> iccExec id2 statusDump archDrvSts NAME ACCESS TYPE VALUE LOW HIGH DESCRIPTION ------------------ ------------- ----- -------- -------- -------- ------------------------- archDrvSts pub r mur (array) Current status of drives No tape in drive Ready to Archive Not initialized 1 Status entries found {id2 {}} Clearly, we still had problems with id2-1. We decided to replace the tape drive at this point, stopped the drift, powered down the crate and replaced id2-1. We rebooted the crate, repeated the tapeLoad commands and still no luck on id2-1. We unloaded the tapes to put in a new tape in id2-1 when Host went south. Shades of excitement. Host rebooted itself. But we could not start_servers. After doing a setup ptvme, we issued the following commands: ~ Host>ptvmeTest -n 1 -l 10 -s 100000 PID: 1576 IOPB size: 64 bytes ping: no operation: read loopCnt: 10 100 loops per dot LWordCnt: 0x000186a0 controller: 0 (defaulted) remNode: 1 --> /dev/ptvme0n1 remAddr: 0x00000000 (defaulted) IxferMode: 0x00 (defaulted) TxferMode: 0x00 (defaulted) errno = 0: open ("/dev/ptvme0n1", O_RDWR) = 3 errno = 0: ioctl (fd=3, PT_IOCTL_GET_PRIORITY, &ptPriority) = 0 ptPriority = 0x03 errno = 0: ioctl (fd=3, PT_IOCTL_GET_VECTOR, &ptVector) = 0 ptVector = 0x01 errno = 0: ioctl (fd=3, PT_IOCTL_GET_TIMEOUT, &ptTimeoutSave) = 0 ptTimeout = 900 ticks errno = 0: ioctl (fd=3, PT_IOCTL_GET_OP_MODE, &ptOpMode) = 0 ptOpMode = 1 SINGLE_IO errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG_MODE, &ptDebugMode) = 0 ptDebugMode = 0 NORMAL errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG, &ptDebugSave) = 0 ptDebug = 0x00000000 errno = 0: ioctl (fd=3, PT_IOCTL_GET_NODE_ID, 0) = 0x00 . 0 9002 ms 20:35 errno = 62: read (fd=3, 0x7F7F2BC0, 0x00061A80) = -1 (Timer expired) CSB status: 0x00000000 AUX = (unknown) CMP = (Never Used) INNA = 0 errno = 0: lseek (fd=3, 0x00000000, SEEK_CUR) = 0x00000000 00000000: 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 00000010: 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F 00000020: 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 00000030: 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F ?> ~ Host> ~ Host>ptvmeTest -n 2 -l 10 -s 100000 PID: 1586 IOPB size: 64 bytes ping: no operation: read loopCnt: 10 100 loops per dot LWordCnt: 0x000186a0 controller: 0 (defaulted) remNode: 2 --> /dev/ptvme0n2 remAddr: 0x00000000 (defaulted) IxferMode: 0x00 (defaulted) TxferMode: 0x00 (defaulted) errno = 0: open ("/dev/ptvme0n2", O_RDWR) = 3 errno = 0: ioctl (fd=3, PT_IOCTL_GET_PRIORITY, &ptPriority) = 0 ptPriority = 0x03 errno = 0: ioctl (fd=3, PT_IOCTL_GET_VECTOR, &ptVector) = 0 ptVector = 0x01 errno = 0: ioctl (fd=3, PT_IOCTL_GET_TIMEOUT, &ptTimeoutSave) = 0 ptTimeout = 900 ticks errno = 0: ioctl (fd=3, PT_IOCTL_GET_OP_MODE, &ptOpMode) = 0 ptOpMode = 1 SINGLE_IO errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG_MODE, &ptDebugMode) = 0 ptDebugMode = 0 NORMAL errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG, &ptDebugSave) = 0 ptDebug = 0x00000000 errno = 0: ioctl (fd=3, PT_IOCTL_GET_NODE_ID, 0) = 0x80430010 . 0 5492 ms 20:36 errno = 5: read (fd=3, 0x7F7F2BC0, 0x00061A80) = -1 (I/O error) CSB status: 0x80430010 AUX = (Timeout - LAN idle > 150 msec - target inited? or VMEbus error) CMP = (Command Completed With Error Status) INNA = 0 errno = 0: lseek (fd=3, 0x00000000, SEEK_CUR) = 0x00000000 00000000: 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 00000010: 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F 00000020: 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 00000030: 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F ?> So, it appears there are ptvme problems: ~ Host>ptvmeReset ptvmeMode: INFO: controller 0 reset (/dev/ptvme0n0) ptvmeMode: INFO: cur debug mode: 0 NORMAL ptvmeMode: INFO: cur debug: 0x00000000 ptvmeMode: INFO: cur timeout: 900 ticks ptvmeMode: INFO: def T/I xfer mode: 0x22 A32:D32 Program, Non-Privileged / A32:D32 Program, Non-Privileged ptvmeMode: INFO: op mode: 1 SINGLE_IO ptvmeMode: INFO: VMEbus priority: 0x03 ptvmeMode: INFO: VMEbus vector: 0x01 ptvmeMode: INFO: intern sem val: 1 ptvmeMode: INFO: user sem val: 1 ptvmeMode: INFO: PT-VME940 node: 0 Further ptvmeTest commands returned similar errors as above. We then rebooted all the crates, taking down host again in the process. This appears to be a MAJOR BUG somewhere in the system. Host rebooted and this time, the servers started back up all right: ~ Host>ptvmeTest -a 0x18000000 -n 1 -l 10 -s 100000 PID: 1264 IOPB size: 64 bytes ping: no operation: read loopCnt: 10 100 loops per dot LWordCnt: 0x000186a0 controller: 0 (defaulted) remNode: 1 --> /dev/ptvme0n1 remAddr: 0x18000000 (defaulted) IxferMode: 0x00 (defaulted) TxferMode: 0x00 (defaulted) errno = 0: open ("/dev/ptvme0n1", O_RDWR) = 3 errno = 0: ioctl (fd=3, PT_IOCTL_GET_PRIORITY, &ptPriority) = 0 ptPriority = 0x03 errno = 0: ioctl (fd=3, PT_IOCTL_GET_VECTOR, &ptVector) = 0 ptVector = 0x01 errno = 0: ioctl (fd=3, PT_IOCTL_GET_TIMEOUT, &ptTimeoutSave) = 0 ptTimeout = 900 ticks errno = 0: ioctl (fd=3, PT_IOCTL_GET_OP_MODE, &ptOpMode) = 0 ptOpMode = 1 SINGLE_IO errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG_MODE, &ptDebugMode) = 0 ptDebugMode = 0 NORMAL errno = 0: ioctl (fd=3, PT_IOCTL_GET_DEBUG, &ptDebugSave) = 0 ptDebug = 0x00000000 errno = 0: ioctl (fd=3, PT_IOCTL_GET_NODE_ID, 0) = 0x00 . 10 10359 ms 20:57 errno = 0: lseek (fd=3, 0x00000000, SEEK_CUR) = 0x00000000 00000000: 01 95 71 6C 01 D4 3A 50 18 04 3A 50 01 D3 6A C0 00000010: 18 03 6A C0 01 D4 B0 00 18 04 B0 00 00 87 FD 40 00000020: 00 00 00 00 00 00 00 00 FF FF FF FF FF FF FF FF 00000030: FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF We set up iop and got the following tape diagnostics: im> iccExec [photoList] statusDump archDrvSts NAME ACCESS TYPE VALUE LOW HIGH DESCRIPTION ------------------ ------------- ----- -------- -------- -------- -------------- ----------- archDrvSts pub r mur (array) Current status of drives Not mounted Not mounted Not initialized 1 Status entries found Error: {id1 {}} {id2 {ICC id2 (crate 1, board 1) is not available Bad ICC}} {id3 {ICC id3 (crate 1, board 2) is not available Bad ICC}} {id4 {ICC id4 (crate 2, board 0) is not available PT Link open failure}} {id5 {ICC id5 (crate 2, board 1) is not available PT Link open failure}} {id6 {ICC id6 (crate 2, board 2) is not available PT Link open failure}} im> iccExec [photoList] archInit Error: {id1 {}} {id2 {ICC id2 (crate 1, board 1) is not available Bad ICC}} {id3 {ICC id3 (crate 1, board 2) is not available Bad ICC}} {id4 {ICC id4 (crate 2, board 0) is not available PT Link open failure}} {id5 {ICC id5 (crate 2, board 1) is not available PT Link open failure}} {id6 {ICC id6 (crate 2, board 2) is not available PT Link open failure}} We felt we could reboot the crates again, but decided not to keep going in circles and abandoned all hope of getting things working at this point. Meanwhile, wind and dust kept us from opening anyhow. Around 10:45pm, as the winds and dust were dropping, we re-filled the spectro dewars and dismounted the camera to install the spectro corrector and cartridge 5 plate 317. We then found the far left (facing the doghouse from the "front" door of the building) cart bellow had a leak and would not hold pressure beyond 36psi. It looks like the RTV (or something) around the air hose connection was cracked and allowing the leak. We called French who instructed us to bring every bellow down 4 lbs (36,36,36, and 40) to even them out. We did that and successfully dismounted the camera and installed the corrector and cartridge. Right before removing the tertiary bolts, the camera started venting ln2 straight down in the area we would have been to remove the bolts. This does not seem like a good thing. We then decided to address the DA problems again, starting with rebooting the crates again. Amazingly enough, host did not immediately crash this time. This time, ptvmeTest reported what looked like normal results. The archInit command, however, failed again: im> iccExec [photoList] archInit Error: {id1 {}} {id2 {}} {id3 {}} {id4 {ICC id4 (crate 2, board 0) is not available PT Link open failure}} {id5 {ICC id5 (crate 2, board 1) is not available PT Link open failure}} {id6 {ICC id6 (crate 2, board 2) is not available PT Link open failure}} The murmur log was reporting: Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id4 {ICC id4 (crate 2, board 0) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id5 {ICC id5 (crate 2, board 1) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id6 {ICC id6 (crate 2, board 2) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad1 {ICC ad1 (crate 3, board 0) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad2 {ICC ad2 (crate 3, board 1) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad3 {ICC ad3 (crate 3, board 2) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad4 {ICC ad4 (crate 3, board 3) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id4 {ICC id4 (crate 2, board 0) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id5 {ICC id5 (crate 2, board 1) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {id6 {ICC id6 (crate 2, board 2) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad1 {ICC ad1 (crate 3, board 0) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad2 {ICC ad2 (crate 3, board 1) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad3 {ICC ad3 (crate 3, board 2) is not available\n PT Link open failure}} Feb 13 00:17:23 sdsshost IOP 7433 TEXTONLY {ad4 {ICC ad4 (crate 3, board 3) is not available\n PT Link open failure}} We rebooted photo2. Again, sdsshost survived the reboot. archInit did the same thing as before. The murmur log was also reporting: The murmur log was also reporting: Feb 13 00:28:50 sdssid1 dInit TEXTONLY *** WARNING *** dscArch: DLT SCSI ID 1 firmware revision is 55 Feb 13 00:28:51 sdssid2 dInit TEXTONLY *** WARNING *** dscArch: DLT SCSI ID 1 firmware revision is 50 Feb 13 00:28:51 sdssid3 dInit TEXTONLY *** WARNING *** dscArch: DLT SCSI ID 1 firmware revision is 50 although I don't know if this is important or not. As a further test of rebooting crates, we rebooted photo1 and 'host again survived intact. Later, we started a bias drift, and found all but id2 were recording data (despite the error messages below from an archDrvSts). im> iccExec [photoList] statusDump archDrvSts NAME ACCESS TYPE VALUE LOW HIGH DESCRIPTION ------------------ ------------- ----- -------- -------- -------- ------------------------- archDrvSts pub r mur (array) Current status of drives Archiver writing Archiver writing Not initialized 1 Status entries found NAME ACCESS TYPE VALUE LOW HIGH DESCRIPTION ------------------ ------------- ----- -------- -------- -------- ------------------------- archDrvSts pub r mur (array) Current status of drives Drive disabled Archiver writing Not initialized 1 Status entries found NAME ACCESS TYPE VALUE LOW HIGH DESCRIPTION ------------------ ------------- ----- -------- -------- -------- ------------------------- archDrvSts pub r mur (array) Current status of drives Archiver writing Archiver writing Not initialized 1 Status entries found Error: {id1 {}} {id2 {}} {id3 {}} {id4 {ICC id4 (crate 2, board 0) is not available PT Link open failure}} {id5 {ICC id5 (crate 2, board 1) is not available PT Link open failure}} {id6 {ICC id6 (crate 2, board 2) is not available PT Link open failure}} Steph continued to try to get id2 to work, for a short time until the skies began to clear. First, she tried an archLoad, archRewind, then archMount (a repeat of Scot & jeff's earlier attempt). After goDrift -bias was issued, she got the following: "Waiting for command response from id2 (crate 1, ICC 1), control server (client 0)". The watcher lost its connection to the servers at this point. A reboot of both crates and restarting the servers was required. The good news is that again 'host did not crash during this process. In short, she saw the same problem as Jeff and Scot saw earlier. At 03:30, the skies cleared enough for us to open. We went to the field of cartridge 5, plate 317, and saw nothing. A nearby fk5 star was easily found and centered on, but a long exposure time was needed. A glance at the sky told us our problem was the return of clouds. At 05:15, we finally conceded defeat and the telescope was stowed in the enclosure with cartridge 5 left on. Steph then turned her attention back to the archiver. This time, InitNight was rerun. A heartbeat was gotten for all drives, but an error message that id2's tape 1 had a dirty head or a bad tape was received, followed by: "sdssid2 dArch TEXTONLY *** WARNING *** dscArch: Couldn't mount tape 1 - no tape in drive " Even though a fresh tape had been put into the drive earlier in the night, it was decided to do this one more time. InitNight was then run again. The murmur log comments during the initNight -tapeLoad all looked normal, and initNight completed normally. Another goDrift -bias was started. This time, archiving proceeded normally. What can be concluded from all this? Apparently our problems were due to a bad tape, and when the tape in id2-1 was replaced earlier in the evening, the proper sequence of archiver incantations was not made. The question I need to check out next is what is the order of commands in initNight -tapeLoad? They scrolled by so fast in the murmur log that I didn't get the order. I will look at this later. Since only one rather short bias was eventually taken, it was decided to not ship this set of tapes. ******************** Mirror Numbers: Primary: prim stat 0 2 I Received=" 1, 1, 1, 1, 1, 1 axis homed" 0 2 I Received=" 000004850, -000002350, 000000100, -000009500, 000000050, -000 000100 commanded position" 0 2 I Received=" 000004850, -000002350, 000000100, -000009500, 000000050, -000 000100 actual position" setmir values: 0 0 I PrimDesOrient=0.00, -3.90, 3.90, 213.50, 213.50; PrimConstRMS=0.00 Secondary: 0 2 I SecFocus=1550.00 sec stat 0 2 I Received=" 1, 1, 1, 1, 1 axis homed" 0 2 I Received=" 001775850, 001762950, 001752700, -000006200, -000010800 comma nded position" 0 2 I Received=" 001775844, 001762918, 001752669, -000006200, -000010800 actua l position" setmir values: 0 0 I SecDesOrient=1400.00, 5.00, -5.00, 50.00, 69.97; SecConstRMS=0.00 ******************** LN2: The spectrographs were filled at 22:45 and again at 07:30. The imager dewar was swapped out at 09:00. Tapes: Because of the archiver problems mentioned in detail above, endNight was not run, and no tapes will be shipped from tonight. The tapes from tonight are still in the drives. The suspected bad tape from id2-1 (JL 1869) has been put by MONX1. Do not lose this tape, as we want to play with it some more on the next shift, to verify it is indeed a bad tape. Telescope: Cartridge 5 installed. Counterweights at 300. Weather: Skies were partly to mostly cloudy. The first half of the evening, wind gusts were over 35 mph out of the west, preventing us from opening. Dust counts also shot from about 100 to over 700 particles/ft^3 from 20:00-22:30. Temperatures dropped from a few degrees above freezing to a few degrees below during the night. Relative humidity climbed from 20% to almost 70%.