[INSTRM-560] gen2 getFitsCards timed out on visit 4963 Created: 26/Oct/18 Updated: 01/Jul/20 Resolved: 01/Jul/20 |
|
| Status: | Won't Fix |
| Project: | Instrument control development |
| Component/s: | ics_gen2Actor |
| Affects Version/s: | None |
| Fix Version/s: | None |
| Type: | Task | Priority: | Major |
| Reporter: | cloomis | Assignee: | cloomis |
| Resolution: | Won't Fix | Votes: | 0 |
| Labels: | FITS, SPS, Subaru | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||
| Description |
|
{gen2 getFitsCards}
timed out on visit 4963. It looks like status itself was fetched and reported in time, but not the header itself. Due to INSTRM-xxx {gen2Actor}will not be generating FITS headers, so this might not matter. Unless this is from something which affected the continuing of the command. Not sure we will be able to tell. This happened after the gen2Actor had successfully processed over 4000 frames. The log section shows one successful loop and the dud. 2018-10-25 21:37:57.515Z cmds 20 Actor.py:498 new cmd: getVisit 2018-10-25 21:37:57.822Z cmds 20 CommandLink.py:121 > 2 8006 : visit=4962 2018-10-25 21:38:01.513Z cmds 20 Actor.py:498 new cmd: getFitsCards frameid=PFSC00496200 ... 2018-10-25 21:38:01.526Z cmds 20 CommandLink.py:121 > 2 8007 i tel_focus=P_OPT2,3.75 2018-10-25 21:38:01.527Z cmds 20 CommandLink.py:121 > 2 8007 i tel_axes=90.41093543,59.99998368 2018-10-25 21:38:01.528Z cmds 20 CommandLink.py:121 > 2 8007 i tel_rot=90.323,0.0 2018-10-25 21:38:01.529Z cmds 20 CommandLink.py:121 > 2 8007 i tel_adc=IN,0.0 2018-10-25 21:38:01.530Z cmds 20 CommandLink.py:121 > 2 8007 i dome_env=56.7,623.1,278.65,0.0 2018-10-25 21:38:01.531Z cmds 20 CommandLink.py:121 > 2 8007 i outside_env=83.1,623.1,274.34999999999997,0.2 2018-10-25 21:38:01.570Z cmds 20 CommandLink.py:123 > 2 8007 i header='REFURS1PQlM9ICcyMDE4LTEwLTI1JyAgICAgICAgIC8gVVQgZGF0ZSBvZiBPYnN... 2018-10-25 21:38:01.574Z cmds 20 CommandLink.py:121 > 2 8007 : 2018-10-25 21:38:03.069Z cmdr 20 CmdrConnection.py:209 command returned mcs 'expose object expTime=1.0 ' ########### filename: /software/mhs/data/mcs/2018-10-25/PFSC00496200.fits 2018-10-25 21:38:03.246Z cmdr 20 CmdrConnection.py:215 queueing command mcs(expose object expTime=1.0 ) 2018-10-25 21:38:03.270Z cmds 20 Actor.py:498 new cmd: getVisit 2018-10-25 21:38:03.527Z cmds 20 CommandLink.py:121 > 2 8008 : visit=4963 2018-10-25 21:38:07.298Z cmds 20 Actor.py:498 new cmd: getFitsCards frameid=PFSC00496300 ... 2018-10-25 21:38:07.361Z cmds 20 CommandLink.py:121 > 2 8009 i tel_focus=P_OPT2,3.75 2018-10-25 21:38:07.362Z cmds 20 CommandLink.py:121 > 2 8009 i tel_axes=90.41109739000001,60.00001669 2018-10-25 21:38:07.369Z cmds 20 CommandLink.py:121 > 2 8009 i tel_rot=90.323,-2e-06 2018-10-25 21:38:07.373Z cmds 20 CommandLink.py:121 > 2 8009 i tel_adc=IN,0.0 2018-10-25 21:38:07.378Z cmds 20 CommandLink.py:121 > 2 8009 i dome_env=56.7,623.1,278.65,0.0 2018-10-25 21:38:07.380Z cmds 20 CommandLink.py:121 > 2 8009 i outside_env=83.1,623.1,274.34999999999997,0.2 2018-10-25 21:38:14.867Z cmdr 20 CmdrConnection.py:209 command returned mcs 'expose object expTime=1.0 ' actor mcs command expose object expTime=1.0 failed 2018-10-25 21:38:14.872Z cmds 20 CommandLink.py:123 > 2 8009 i header='REFURS1PQlM9ICcyMDE4LTEwLTI1JyAgICAgICAgIC8gVVQgZGF0ZSBvZiBPYnN... 2018-10-25 21:38:14.874Z cmds 20 CommandLink.py:121 > 2 8009 : |
| Comments |
| Comment by cloomis [ 26/Oct/18 ] |
|
And a getVisit a bit later. Good one followed by the failure. Need to turn up logging on the Gen2 side. 2018-10-26 04:30:45.661Z cmdr 20 CmdrConnection.py:215 queueing command mcs(expose object expTime=0.5 ) 2018-10-26 04:30:45.690Z cmds 20 Actor.py:498 new cmd: getVisit 2018-10-26 04:30:45.978Z cmds 20 CommandLink.py:121 > 2 1313 : visit=7335 2018-10-26 04:30:49.057Z cmds 20 Actor.py:498 new cmd: getFitsCards frameid=PFSC00733500 ... 2018-10-26 04:30:49.086Z cmds 20 CommandLink.py:121 > 2 1314 i tel_focus=P_OPT2,3.75 2018-10-26 04:30:49.087Z cmds 20 CommandLink.py:121 > 2 1314 i tel_axes=90.41015035999999,30.00001137 2018-10-26 04:30:49.088Z cmds 20 CommandLink.py:121 > 2 1314 i tel_rot=90.323,-2e-06 2018-10-26 04:30:49.089Z cmds 20 CommandLink.py:121 > 2 1314 i tel_adc=IN,21.96 2018-10-26 04:30:49.090Z cmds 20 CommandLink.py:121 > 2 1314 i dome_env=11.8,621.2,277.65,0.4 2018-10-26 04:30:49.091Z cmds 20 CommandLink.py:121 > 2 1314 i outside_env=13.8,621.2,277.04999999999995,3.8 2018-10-26 04:30:49.115Z cmds 20 CommandLink.py:123 > 2 1314 i header='REFURS1PQlM9ICcyMDE4LTEwLTI2JyAgICAgICAgIC8gVVQgZGF0ZSBvZiBPYnN... 2018-10-26 04:30:49.118Z cmds 20 CommandLink.py:121 > 2 1314 : 2018-10-26 04:30:50.589Z cmdr 20 CmdrConnection.py:209 command returned mcs 'expose object expTime=0.5 ' ########### filename: /software/mhs/data/mcs/2018-10-26/PFSC00733500.fits 2018-10-26 04:30:50.818Z cmdr 20 CmdrConnection.py:215 queueing command mcs(expose object expTime=0.5 ) 2018-10-26 04:30:50.830Z cmds 20 Actor.py:498 new cmd: getVisit 2018-10-26 04:30:59.120Z cmdr 20 CmdrConnection.py:209 command returned mcs 'expose object expTime=0.5 ' actor mcs command expose object expTime=0.5 failed |
| Comment by cloomis [ 20/Jun/20 ] |
|
Bump. In this case we some events from the PFS side of the Gen2 connection. I think the reqframes request and reply should not show a delay. Waiting for timestamps from the other side of the connection to know where the problem is.
2020-06-19 08:52:06.297Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:52:06,299 | I | PFS.py:643 (reqframes) | reqframes num=100 type='A' 2020-06-19 08:52:07,798 | I | PFS.py:647 (reqframes) | framelist: ['PFSA02011200' ... 2020-06-19 08:52:07.809Z cmds 20 CommandLink.py:121 > 2 16 : visit=20112 2020-06-19 08:53:04.726Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:53:04,728 | I | PFS.py:643 (reqframes) | reqframes num=100 type='A' 2020-06-19 08:53:33.225Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:54:01.639Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:54:27.001Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:54:52.997Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:55:19.056Z cmds 20 Actor.py:507 new cmd: getVisit 2020-06-19 08:55:39,143 | I | PFS.py:647 (reqframes) | framelist: ['PFSA02011300' ... 2020-06-19 08:55:39,152 | I | PFS.py:643 (reqframes) | reqframes num=100 type='A' 2020-06-19 08:55:39.152Z cmds 20 CommandLink.py:121 > 2 17 : visit=20113 |
| Comment by cloomis [ 01/Jul/20 ] |
|
FITS headers are fetched entirely differently now, and the real problem was probably covered by |