Details
-
Type:
Story
-
Status: Done
-
Resolution: Done
-
Fix Version/s: None
-
Component/s: ts_main_telescope
-
Labels:
-
Story Points:1
-
Sprint:TSSW Sprint - Nov 07 - Nov 21
-
Team:Telescope and Site
-
Urgent?:No
Description
The rotation telemetry topic is increasingly delayed over time.
I added a diagnostic print statement to the MTRotator CSC in an effort to figure out if this was likely in the low-level controller or the CSC. The statement is in the callback function that is called whenever the CSC reads telemetry from the low-level controller. It prints two values:
- telemetry_age: rcv_time - telemetry header timestamp, where rcv_time is the time at which the telemetry calllback function is called to process low-level telemetry.
- write rotation delay: the time just after the "rotation" SAL event is sent - rcv_time.
What I see is that relemetry_tag increases slowly and apparently fairly linearly, whereas write rotation delay does not change.
telemetry_age=0.084; write rotation delay=0.001
|
telemetry_age=0.084; write rotation delay=0.001
|
telemetry_age=0.084; write rotation delay=0.001
|
telemetry_age=0.085; write rotation delay=0.001
|
telemetry_age=0.085; write rotation delay=0.001
|
telemetry_age=0.085; write rotation delay=0.001
|
telemetry_age=0.086; write rotation delay=0.001
|
telemetry_age=0.086; write rotation delay=0.001
|
telemetry_age=0.086; write rotation delay=0.001
|
telemetry_age=0.087; write rotation delay=0.001
|
telemetry_age=0.087; write rotation delay=0.001
|
telemetry_age=0.087; write rotation delay=0.001
|
telemetry_age=0.088; write rotation delay=0.001
|
telemetry_age=0.088; write rotation delay=0.001
|
telemetry_age=0.088; write rotation delay=0.001
|
telemetry_age=0.089; write rotation delay=0.001
|
telemetry_age=0.089; write rotation delay=0.001
|
telemetry_age=0.089; write rotation delay=0.001
|
telemetry_age=0.090; write rotation delay=0.001
|
telemetry_age=0.090; write rotation delay=0.001
|
telemetry_age=0.091; write rotation delay=0.001
|
telemetry_age=0.091; write rotation delay=0.001
|
telemetry_age=0.091; write rotation delay=0.001
|
telemetry_age=0.092; write rotation delay=0.001
|
telemetry_age=0.092; write rotation delay=0.001
|
telemetry_age=0.092; write rotation delay=0.001
|
telemetry_age=0.093; write rotation delay=0.001
|
telemetry_age=0.093; write rotation delay=0.001
|
telemetry_age=0.093; write rotation delay=0.001
|
telemetry_age=0.094; write rotation delay=0.001
|
telemetry_age=0.094; write rotation delay=0.001
|
telemetry_age=0.094; write rotation delay=0.001
|
telemetry_age=0.095; write rotation delay=0.001
|
telemetry_age=0.095; write rotation delay=0.001
|
telemetry_age=0.095; write rotation delay=0.001
|
telemetry_age=0.096; write rotation delay=0.001
|
telemetry_age=0.096; write rotation delay=0.001
|
telemetry_age=0.097; write rotation delay=0.001
|
telemetry_age=0.097; write rotation delay=0.001
|
telemetry_age=0.097; write rotation delay=0.001
|
telemetry_age=0.098; write rotation delay=0.001
|
telemetry_age=0.098; write rotation delay=0.001
|
telemetry_age=0.098; write rotation delay=0.001
|
telemetry_age=0.099; write rotation delay=0.001
|
telemetry_age=0.099; write rotation delay=0.001
|
telemetry_age=0.099; write rotation delay=0.001
|
telemetry_age=0.100; write rotation delay=0.001
|
...
|
The message is printed every 25 telemetry samples. After many minutes the time is up to 0.465 seconds.
I strongly suspect the error is inside the low-level controller and I hope you will be willing to rule this out before I look for it in the CSC. I'm having trouble imagining how the CSC could do this (especially with such large delays).
The only possible explanation I have come up with is an algorithm such as this:
timestamp = get_current_time()
|
while True:
|
compute and send telemetry
|
sleep telemetry_interval
|
timestamp = old_timestamp + telemetry_interval
|
The timestamp would fall further behind in each iteration by the amount of the time spent in the "compute and send telemetry" step.
Attachments
Activity
| Field | Original Value | New Value |
|---|---|---|
| Labels | M2 |
| Urgent? | on | off |
| Epic Link | DM-27721 [ 442128 ] |
| Attachment | timestamp_rotator.ipynb [ 64548 ] |
| Sprint | TSSW Sprint - Nov 07 - Nov 21 [ 1200 ] |
| Attachment | show_mismatched_delays.py [ 64550 ] |
| Attachment | show_mismatched_delays_modified.py [ 64551 ] |
| Status | To Do [ 10001 ] | In Progress [ 3 ] |
| Story Points | 1 |
| Attachment | timestamp_rotator.ipynb [ 64548 ] |
| Attachment | timestamp_rotator.ipynb [ 64553 ] |
| Attachment | timestamp_rotator_90sec.ipynb [ 64554 ] |
| Attachment | diff_sal_sndStamp.png [ 64555 ] | |
| Attachment | diff_sal_rcvStamp.png [ 64556 ] |
| Attachment | diff_sal_sndStamp_after_90sec.png [ 64557 ] |
| Reviewers | Russell Owen [ rowen ] | |
| Status | In Progress [ 3 ] | In Review [ 10004 ] |
| Status | In Review [ 10004 ] | Reviewed [ 10101 ] |
| Attachment | delay times after Te-Wei's fix.txt [ 64570 ] |
| Resolution | Done [ 10000 ] | |
| Status | Reviewed [ 10101 ] | Done [ 10002 ] |