From: Craig Loomis
Subject: Re: 2.5m obslog 20040514 (MJD 53140)
Date: Sat, 15 May 2004 18:09:46 -0600
On May 15, 2004, at 5:52 AM, John Barentine wrote:
>
> Spectro guider problem:
> -----------------------
> During the acquisition of the field of Plate 1643, guider frames
> stopped being
> transferred ot the guider monitor.  They were being taken and written
> to disk,
> but without a display we had no way of keeping an eye on them.  In
> addition,
> startGuider and stopGuider commands were backing up and would suddenly
> be
> issued in rapid succession:
>
> 07:02:18 34221 SOPGUI: startGuider 10
> 07:02:27 34221 SOPGUI: startGuider 10
> 07:05:15 34221 SOPGUI: stopGuider
> 07:05:25 34221 SOPGUI: startGuider 10
> 07:05:52 34221 SOPGUI: stopGuider
> 07:05:53 34221 SOPGUI: startGuider 10
>
> We found that when a stopMon was issued, transferring of frames would
> resume.
> Jurek repeatedly tried exiting and restarting SOPGUI, then tried
> restarting
> SOP altogether.  Meanwhile, the guider frames eventually stopped being
> written
> to disk altogether (tccmon indicated exposures *were* being taken,
> however).
>
>  From the guider log:
>
> 2.64 2004-05-15 06:03:27.608Z 06:03:50.246Z 0 0 I GCamReply="2 2 0 0
> 384 256 20.
> 00 6 10.00 "image: binXY begXY sizeXY expTime camID temp""
> 4.17 2004-05-15 06:03:59.119Z 06:04:23.286Z 0 0 I GCamReply="2 2 0 0
> 384 256 20.
> 00 6 10.00 "image: binXY begXY sizeXY expTime camID temp""
> 11.12 2004-05-15 06:06:07.289Z 06:06:38.406Z 0 0 I GCamReply="2 2 0 0
> 384 256 20
>  .00 6 10.00 "image: binXY begXY sizeXY expTime camID temp""
> 28.21 2004-05-15 06:12:47.358Z 06:13:20.569Z 0 0 I GCamReply="1 1 0 0
> 768 512 5.
> 00 6 10.00 "image: binXY begXY sizeXY expTime camID temp""
> could not reply: 0 0 F GCamReply="Time limit exceeded; exposure aborted
>                              "
> 17.01 2004-05-15 06:14:00.398Z 06:14:22.409Z 0 0 F GCamReply="Time
> limit exceede
> d; exposure aborted                                      "
> could not reply: 0 0 F GCamReply="Time limit exceeded; exposure aborted
>
> Craig said this problem happens when a guider image comes in as SOS is
> getting
> its information, causing the system to momentarily become slow.  The
> guider
> Mac then gets confused as it lags behind what's actually happening and
> first
> slows, then halts.  An occasional failure then becomes catastrophic as
> the Mac
> gets out of sync.  A diagnostic Craig recommended is:
>
> ssh arc@pod (password in control room)
>
> cat logs/from.tcc25m/current.log | gcamtime.py
> (Returns a log of guider events)
>
>         - or -
>
> tail -f logs/from.tcc25m/current.log | gcamtime.py
> (Updates events to screen as they are logged)
>
> (This information will be folklored for future reference.)
>
> Command initiation-to-completion times are given in the first column;
> normal
> times for routine guiding are ~2-3 seconds (the unbinned images taken
> in field
> acquisition require longer times).  The output copied above shows that
> normal
> guiding ended at 06:03:59Z; times got progressively longer until the
> command
> timed out at 06:12:47Z. From that time on, only rebooting of the
> guider Mac
> (to resync the operations) would have saved us.  Craig mentioned a
> problem
> with the NFS stacks on the guider Mac, which fixing might solve the
> problem.
>
     When investigating the sos vs. guider mac problem last month, I
switched from one antique third-party NFS stack (NFS/Share) to another,
slightly less old one (MacNFS). But it appears that MacNFS might be
getting horribly messed up by the delayed writes and causing the Mac to
become essentially unresponsive. With that notion, I swapped back to
NFS/Share.
    Blecch. I need to go wash my hands.
  - craig