Set DOM polling interval based on the time at the start of the loop instead of the end - #757
Conversation
|
/azp run |
|
Azure Pipelines successfully started running 1 pipeline(s). |
b20422c to
1f21007
Compare
|
/azp run |
|
Azure Pipelines successfully started running 1 pipeline(s). |
…nstead of the end. Signed-off-by: aditya-nexthop <aditya@nexthop.ai>
1f21007 to
c1e6d5f
Compare
|
/azp run |
|
Azure Pipelines successfully started running 1 pipeline(s). |
There was a problem hiding this comment.
Pull request overview
This PR adjusts the xcvrd DOM monitoring loop scheduling so the next DOM polling window is calculated from the timestamp at the start of the loop iteration, instead of from the time after all ports have been processed. This aligns the effective polling period with DOM_INFO_UPDATE_PERIOD_SECS per the expectation in issue #756 and reduces idle gaps after a full polling pass.
Changes:
- Capture
nowat the beginning of each DOM monitoring loop iteration. - Use that loop-start timestamp to determine whether an update is due and to compute
next_periodic_db_update_time.
| now = datetime.datetime.now() | ||
| if next_periodic_db_update_time <= now: |
There was a problem hiding this comment.
The new scheduling logic depends on capturing now at the start of the loop and using it to compute next_periodic_db_update_time. There isn’t currently a unit test that asserts this behavior for a non-zero DOM_INFO_UPDATE_PERIOD_SECS (e.g., by mocking datetime.datetime.now() to simulate a long per-iteration processing time and verifying the next update time is based on the loop-start timestamp, not the loop-end timestamp). Adding such a test would help prevent regressions to the original timing bug.
mihirpat1
left a comment
mihirpat1
left a comment
There was a problem hiding this comment.
@aditya-nexthop @prgeor This change looks correct for fixing the interval anchoring. However, a broader question: if each port takes ~1s to update DOM data and there are 64 ports, the loop takes ~64s per iteration. With DOM_INFO_UPDATE_PERIOD_SECS potentially shorter than that, are we okay with the loop running back-to-back with no sleep/yield? Could there be a concern about starving other tasks or excessive CPU usage in that scenario?
Hi @mihirpat1, as per #758 the wait is primarily due to the time waiting for select to timeout. We don't need to merge this PR if we merge #758 as #758 includes these changes. I will close this PR once #758 merges. |
@mihirpat1 in that case we may have to define |
@prgeor That's correct - defining it per platform can help in addressing this. |
|
@aditya-nexthop can you make this a platform adjusted variable? |
Yes, that's a good idea, created #774 to work on this in a new PR. |
…r transceiver DOM polling (#864) <!-- Provide a general summary of your changes in the Title above --> #### Description This PR optimizes the DOM (Digital Optical Monitoring) polling loop in xcvrd by improving port update event handling and reducing unnecessary wait times. The changes include: 1. **Refactored port update handling** - Extracted port update event processing into a dedicated `check_port_update()` method for better code organization and reusability 2. **Optimized timeout strategy** - Introduced two-tier timeout mechanism: - 1000ms timeout when waiting for port updates before DOM polling begins and after when it completes until the next polling cycle - 100ms timeout during DOM polling to minimize delays while still handling port events 3. **Improved loop structure** - Restructured the main loop to handle port updates before entering the DOM polling phase, preventing unnecessary blocking 4. **Added comprehensive unit tests** - Created tests covering various scenarios including multiple ports, timing edge cases, and stop event handling fixes #759 and builds on #757 #### Motivation and Context Before the change, the DOM monitoring loop would wait up to 1 second (`SELECT_TIMEOUT_MSECS`) for port update events during each iteration of the physical port loop. This caused significant delays in DOM data collection, especially on systems with many ports. **Problem:** With the 1-second timeout being called for every physical port, the DOM polling could take an excessive amount of time to complete, delaying DOM polling updates. **Solution:** By separating port update handling from DOM polling and using a shorter 100ms timeout during the polling phase, the loop can complete much faster while still being responsive to port change events. The 1-second timeout is only used when explicitly waiting for port updates before starting the next DOM polling cycle. #### How Has This Been Tested? 1. **Unit Tests Added** - Comprehensive test coverage for the new `check_port_update()` method including: - Scenario with no link change affected ports - Link change affected port with past timestamp (should trigger immediate update) - Link change affected port with future timestamp (should defer update) - Multiple ports with mixed ready/not-ready states - Stop event handling during processing 2. **CPU usage profiling**: Measured for 10 minutes after restarting `xcvrd` on a switch fully populated with optical transceivers. - Before the change (includes changes from #757) <img width="937" height="257" alt="image" src="https://github.com/user-attachments/assets/224dca27-c0fa-4059-b7b1-fdcd9a4ed66e" /> - After the change <img width="934" height="249" alt="image" src="https://github.com/user-attachments/assets/8efa3d40-1e25-45c8-a48a-088d55ff34c3" /> The CPU usage is slightly higher during active polling as it spends less time waiting (100ms) between interfaces and then the loop spends time waiting for port change updates in 1s chunks. 3. **Measuring actual DOM update times** - Before change: We are not able to poll every 60 seconds (takes 90 sec+) on a switch fully populated with optical transceivers ``` $ while true; do sonic-db-dump -n STATE_DB -y -k "TRANSCEIVER_DOM_SENSOR|Ethernet112" | grep last_update_time; sleep 10; done | uniq "last_update_time": "Tue Feb 24 19:25:57 2026", "last_update_time": "Tue Feb 24 19:27:32 2026", "last_update_time": "Tue Feb 24 19:29:06 2026", "last_update_time": "Tue Feb 24 19:30:40 2026", "last_update_time": "Tue Feb 24 19:32:13 2026", "last_update_time": "Tue Feb 24 19:33:47 2026", ``` - After change: Updates happen every 60 seconds for a specified interface ``` $ while true; do sonic-db-dump -n STATE_DB -y -k "TRANSCEIVER_DOM_SENSOR|Ethernet112" | grep last_update_time; sleep 10; done | uniq "last_update_time": "Tue Feb 24 19:17:09 2026", "last_update_time": "Tue Feb 24 19:18:10 2026", "last_update_time": "Tue Feb 24 19:19:10 2026", "last_update_time": "Tue Feb 24 19:20:10 2026", "last_update_time": "Tue Feb 24 19:21:11 2026", "last_update_time": "Tue Feb 24 19:22:11 2026", ``` #### Additional Information (Optional) **Key Technical Changes:** - New constants: `PORT_UPDATE_EVENT_SELECT_TIMEOUT_MSECS` (1000ms) and `PORT_UPDATE_EVENT_SELECT_TIMEOUT_FAST_MSECS` (100ms) - Modified `PortChangeObserver.handle_port_update_event()` to accept a configurable timeout parameter - The periodic update interval calculation now uses `dom_loop_start_time` to maintain consistent intervals regardless of loop execution time **Backward Compatibility:** This change is fully backward compatible and does not affect the external API or configuration. #### Tested branch - [x] master - [x] 202605: already in Nexthop's internal 202605 branch Signed-off-by: Sonic Build Admin <sonicbld@microsoft.com>
Description
During profiling we found that there was a significant period of time when transceiver information was not being updated.
Upon study, it was seen that for DOM_INFO_UPDATE_PERIOD_SECS after the last transceiver in the loop was polled, there were no updates.
Motivation and Context
fixes #756
This improves DOM polling performance of transceivers in
xcvrdand correctly ensures that DOM_INFO_UPDATE_PERIOD_SECS time elapses between updating a specific transceiver.How Has This Been Tested?
We did a CPU profiling without and with the change over a 10 min window just after
xcvrdstartsBefore:
After:
The CPU is more uniformly utilized after the change instead of staying idle when more than DOM_INFO_UPDATE_PERIOD_SECS has already passed since a specific transceiver was polled.
Additional Information (Optional)