Timeout crashes HWP PID main process
Open
Nobody has claimed this yet.
bug
- Dominant language
- Python
- Stars
- 17
- Forks
- 20
- Avg merge
- 1h 22m
- Merged PRs (30d)
- 2
Description
Saw this this morning on satp1:
2024-10-28 11:50:39.622 2024-10-28T11:50:39+0000 DecodedResponse(msg_type='measure', msg='Current frequency = 1.999', measure=1.999)
2024-10-28 11:50:39.622 2024-10-28T11:50:39+0000 Finding target CHWP Frequency
2024-10-28 11:50:40.123 2024-10-28T11:50:40+0000 ['R014007D0']
2024-10-28 11:50:40.123 2024-10-28T11:50:40+0000 DecodedResponse(msg_type='read', msg='Setpoint = 2.0', measure=2.0)
2024-10-28 11:50:40.123 2024-10-28T11:50:40+0000 Finding CHWP Direction
2024-10-28 11:50:42.626 2024-10-28T11:50:42+0000 Caught timeout waiting for response from PID controller. Trying again...
2024-10-28 11:50:44.290 2024-10-28T11:50:44+0000 ['R02400000']
2024-10-28 11:50:44.290 2024-10-28T11:50:44+0000 DecodedResponse(msg_type='read', msg='Direction = Forward', measure=0)
2024-10-28 11:50:44.491 2024-10-28T11:50:44+0000 Finding CHWP Frequency
2024-10-28 11:50:44.991 2024-10-28T11:50:44+0000 ['\x00\x00\x00\x00\x00\x00\x00\x00\x00X012.001']
2024-10-28 11:50:44.991 2024-10-28T11:50:44+0000 DecodedResponse(msg_type='error', msg='Unrecognized response', measure=None)
2024-10-28 11:50:44.991 2024-10-28T11:50:44+0000 Error reading freq: Unrecognized response
2024-10-28 11:50:44.991 2024-10-28T11:50:44+0000 ['\x00\x00\x00\x00\x00\x00\x00\x00\x00X012.001']
2024-10-28 11:50:44.992 2024-10-28T11:50:44+0000 DecodedResponse(msg_type='error', msg='Unrecognized response', measure=None)
2024-10-28 11:50:44.992 2024-10-28T11:50:44+0000 Error reading freq: Unrecognized response
2024-10-28 11:50:44.992 2024-10-28T11:50:44+0000 ['\x00\x00\x00\x00\x00\x00\x00\x00\x00X012.001']
2024-10-28 11:50:44.992 2024-10-28T11:50:44+0000 DecodedResponse(msg_type='error', msg='Unrecognized response', measure=None)
2024-10-28 11:50:44.992 2024-10-28T11:50:44+0000 Error reading freq: Unrecognized response
2024-10-28 11:50:44.993 2024-10-28T11:50:44+0000 main:104 CRASH: [Failure instance: Traceback: <class 'ValueError'>: Could not get current frequency
2024-10-28 11:50:44.993 /usr/lib/python3.10/threading.py:1016:_bootstrap_inner
2024-10-28 11:50:44.993 /usr/lib/python3.10/threading.py:953:run
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/_threads/_threadworker.py:49:work
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/_threads/_team.py:192:doWork
2024-10-28 11:50:44.993 --- <exception caught here> ---
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/python/threadpool.py:269:inContext
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/python/threadpool.py:285:<lambda>
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/python/context.py:117:callWithContext
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/twisted/python/context.py:82:callWithContext
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/ocs/ocs_agent.py:984:_running_wrapper
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/socs/agents/hwp_pid/agent.py:174:main
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/socs/agents/hwp_pid/agent.py:121:_get_data_and_publish
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/socs/agents/hwp_pid/agent.py:33:get_pid_state
2024-10-28 11:50:44.993 /opt/venv/lib/python3.10/site-packages/socs/agents/hwp_pid/drivers/pid_controller.py:248:get_freq
2024-10-28 11:50:44.993 ]
2024-10-28 11:50:44.993 2024-10-28T11:50:44+0000 main:104 Status is now "done".
2024-10-28 13:28:49.827 2024-10-28T13:28:49+0000 start called for main
2024-10-28 13:28:49.827 2024-10-28T13:28:49+0000 main:105 Status is now "starting".
2024-10-28 13:28:49.829 2024-10-28T13:28:49+0000 main:105 Status is now "running".
2024-10-28 13:28:49.830 2024-10-28T13:28:49+0000 Connected to PID controller
2024-10-28 13:28:49.831 2024-10-28T13:28:49+0000 Finding CHWP Frequency
2024-10-28 13:28:50.332 2024-10-28T13:28:50+0000 ['X011.999']
2024-10-28 13:28:50.332 2024-10-28T13:28:50+0000 DecodedResponse(msg_type='measure', msg='Current frequency = 1.999', measure=1.999)
2024-10-28 13:28:50.332 2024-10-28T13:28:50+0000 Finding target CHWP Frequency
2024-10-28 13:28:50.833 2024-10-28T13:28:50+0000 ['R014007D0']
2024-10-28 13:28:50.833 2024-10-28T13:28:50+0000 DecodedResponse(msg_type='read', msg='Setpoint = 2.0', measure=2.0)
Recovery was just restarting the main process, which you can see in the logs. Resolving this will contribute to the effort in #721.
socs image tag: v0.5.1-22-g7d2f158-dev
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with the get_freq call in socs/agents/hwp_pid/drivers/pid_controller.py and the main flow in socs/agents/hwp_pid/agent.py, using the logged timeout and unrecognized response as the failure case. Determine how the main process should handle this controller error, then verify that it no longer crashes and that normal PID operation still recovers.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- embedded-iot
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 35/100