Date: Tue, 30 Apr 2002 09:06:40 -0700
From: Russell E Owen
Subject: Telescope halt (Re: 2.5m obslog 20020429 (MJD 52394))
Two different things appear to be going on here.
First of all, the TCC clearly is to blame for losing messages. The 3.5m also saw this problem (and I sent an email warning about it) and it seems correlated with installing Multinet. TCC software version 2.6.2 is needlessly reliant on a responsive message hub, and I have improved the design in 2.6.3. The 3.5m has been running with this for several nights with no problems.
Nonetheless, the delays that caused the problem are unacceptable and I'm sorry to say, but I recommend deinstalling Multinet, at least until we can figure out what's going on or get a bug fix update from the company. This will put the SDSS TCC back in the state it was for the last dark run, and I would like permission to do this.
Next bright time I recommend installing TCC verison 2.6.3; it will make tracking and such more robust in the fact of message hub delays (which should not happen, but why not have a more robust architecture?).
Secondly, it MCP got upset. It may well be that a tracking update from the TCC was late (the message hub delays could cause that); if it wasn't that then it probably wasn't caused by the TCC. Robert, can you figure it out?
bash-2.04$ ./combinelogs.py -d 2002-04-30T02:55:36.940Z -b 0 -a 60 from.tcc25m from.MCP
...
from.tcc25m          2002-04-30T02:55:37.898Z 0 0 I PrimOrient=0.00, -12.16, 22.81, 1257.41, 642.19
from.tcc25m          2002-04-30T02:55:38.514Z 0 0 I  SecCmdMount=-3372251.,-3406128.,-3387398.,-9714.,-9140.; CmdDTime=21.8
from.MCP             2002-04-30T02:55:38.666Z AZ  STATUS
from.MCP             2002-04-30T02:55:38.716Z 34.797774 -1.073774 10570.660624 0 0.000000 OK
...(many status messages from the MCP while the TCC output nothing -- indicating that the message hub was stalled)
from.MCP             2002-04-30T02:55:58.983Z AZ  STATUS
from.MCP             2002-04-30T02:55:59.036Z 23.256032 0.000000 10590.977876 0 0.000000 OK
from.MCP             2002-04-30T02:55:59.122Z ALT STATUS
from.MCP             2002-04-30T02:55:59.170Z 35.213989 0.000000 10591.113340 0 0.000000 OK
from.MCP             2002-04-30T02:55:59.280Z ROT STATUS
from.MCP             2002-04-30T02:55:59.326Z 20.999437 0.000000 10591.272981 0 0.000000 OK
from.MCP             2002-04-30T02:56:02.806Z AZ  MOVE 23.2297522 -0.0045380 10590.61020
from.MCP             2002-04-30T02:56:02.826Z ERR: MOVE OK
from.tcc25m          2002-04-30T02:56:05.113Z 0 0 I Modu="prt_ReadReplySet"; Text="the following replies were read:"
from.MCP             2002-04-30T02:56:05.780Z ALT MOVE 35.2100619 0.0013910 10590.61020
from.MCP             2002-04-30T02:56:05.795Z ERR: MOVE OK
from.tcc25m          2002-04-30T02:56:06.543Z 0 0 W Text="process T_TRACK lost 1 messages that could not be sent to the message hub"
from.tcc25m          2002-04-30T02:56:06.658Z 0 0 F Modu="prt_ReadReplySet"; Text="too many replies on port LTA19:"
from.tcc25m          2002-04-30T02:56:06.758Z 0 0 I  SecOrient=-2690.23, -2.66, -9.71, 0.43, 107.67
from.tcc25m          2002-04-30T02:56:06.859Z 0 0 W Text="process T_TRACK lost 1 messages that could not be sent to the message hub"
from.tcc25m          2002-04-30T02:56:06.860Z 0 0 I Modu="prt_ReadReplySet"; Text="the following replies were read:"
from.tcc25m          2002-04-30T02:56:06.959Z 0 0 W Text="process T_COLLIMATE lost 1 messages that could not be sent to the message hub"
from.tcc25m          2002-04-30T02:56:06.959Z 0 0 I Modu="prt_ReadReplySet"; Text="ERR: MOVE"
Finally, could someone please issue a PR against the TCC?
Regards,
-- Russell
>Telescope halt and error messages in Watcher
>----------------------------------------------
>
>
>Text="failed to move one or more axes":AxisNoTrack:T-T-T (2002-04-30 02:56:25Z)
>Modu="axe i SchMove" (2002-04-30 02:56:25Z)
>Modu="cam i MeasStars"(2002-04-30 02:56:25Z)
>Modu="exe Track" (2002-04-30 02:56:25Z)
>Modu="prt ReadReplySet" (2002-04-30 02:56:25Z)
>TCCStatus:alt (axis halted by a problem: 2002-04-30 02:56:25Z)
>AxisStop:alt (axis stopped: 2002-04-30 02:56:25Z)
>TCCStatus:rot (axis halted by a problem: 2002-04-30 02:56:25Z)
>AxisStop:rot (axis stopped: 2002-04-30 02:56:25Z)
>TCCStatus:az (axis halted by a problem: 2002-04-30 02:56:25Z)
>AxisStop:az (axis stopped: 2002-04-30 02:56:25Z)
>
>Pete dug out the timestamp of the track command that failed.
>Pete logged in to arc@pod.apo.nmsu.edu and used the command:
>
>  gimme -b 2002-04-29T  from.tcc25m|more
>
>then found the track command that failed, time-stamped at
>2002-04-30T02:55:28.399Z during which we see the following messages
>starting at 2002-04-30T02:56:05.113Z (time stamps and command prefixes
>removed to reduce line wrap):
>
>Modu="prt_ReadReplySet"; Text="the following replies were read:"
>
>Text="process T_TRACK lost 1 messages that could not be sent to the
>message hub"
>
>Modu="prt_ReadReplySet"; Text="too many replies on port LTA19:"
>
>SecOrient=-2690.23, -2.66, -9.71, 0.43, 107.67
>
>Text="process T_TRACK lost 1 messages that could not be sent to the
>message hub"
>
>Modu="prt_ReadReplySet"; Text="the following replies were read:"
>
>Text="process T_COLLIMATE lost 1 messages that could not be sent to the
>message hub"
>
>Modu="prt_ReadReplySet"; Text="ERR: MOVE"
>
>Modu="prt_ReadReplySet"; Text="too many replies on port LTA19:"
>
>Modu="prt_ReadReplySet"; Text="the following replies were read:"
>
>Modu="prt_ReadReplySet"; Text="ERR: MOVE"
>
>Text="failed to move one or more axes"; AxisNoTrack=T,T,T;
>AxisErrCode="ControllerErr","ControllerErr","ControllerErr"
>AxisStop="TTT"
>
>Modu="axe_i_SchMove"; Text="tracking failed; axes halted"
>
>SchMoveTimes=-4.0, -4.0, -4.0, -4.0
>
>Modu="exe_Track"; Text="no longer tracking"
>
>TCCStatus="TTT","NNN"; TCCPos=23.19,35.22,20.95; AxePos=23.26,35.21,21.00
>
>Text="process T_STATUS lost 21 messages that could not be sent to the
>message hub"