test_po_cleanup: fix loganalyzer marker loss under CPU stress by Pterosaur · Pull Request #23291 · sonic-net/sonic-mgmt

Pterosaur · 2026-03-25T05:35:51Z

Description of PR

Fix test_po_cleanup_after_reload failure caused by LogAnalyzer end marker being lost under heavy CPU stress and syslog load.

Type of change

Back port request

Approach

What is the motivation for this PR?

test_po_cleanup_after_reload fails consistently with:

RuntimeError: cannot find marker end-LogAnalyzer-port_channel_cleanup.xxx in /var/log/syslog

Two issues combine to lose the loganalyzer end marker:

Logrotate fires mid-test: The system logrotate timer can trigger during config_reload under CPU stress, rotating /var/log/syslog. Markers get pushed beyond syslog.1 into compressed archives (syslog.2.gz) that loganalyzer does not search.
Syslog UDP buffer overflow: Under heavy CPU load (all cores running yes), rsyslogd cannot keep up with syslog traffic and its UDP receive buffer overflows, silently dropping the end marker written via /dev/log.

This supersedes PR #22776 which attempted to fix this by writing markers directly to /var/log/syslog, but that approach causes log timestamp ordering issues.

How did you do it?

Three changes to test_po_cleanup_after_reload:

Wrap with DisableLogrotateCronContext — stops the logrotate timer and cron job for the duration of the test, preventing mid-test syslog rotation.
Move CPU stress cleanup into a try/finally block inside with loganalyzer: — killall yes runs before loganalyzer __exit__ places the end marker, so rsyslogd is no longer competing for CPU.
Poll /var/log/syslog file size until stable — after stopping CPU stress, wait for two consecutive 10-second intervals with no file growth before allowing the end marker to be placed. This ensures rsyslogd has drained any remaining socket buffer backlog.

How did you verify/test it?

Without fix: Test fails consistently with RuntimeError: cannot find marker end-LogAnalyzer-...
With fix: PASSED (1 passed in 1153s / 19:13)

Intermediate approaches that did NOT work:

DisableLogrotateCronContext alone: logrotate is only one of two root causes; the syslog buffer overflow also drops the marker
killall yes + no drain wait: rsyslogd buffer backlog can take minutes to drain after CPU stress ends

Any platform specific information?

Not platform-specific. Applies to any setup with enough port channels to generate heavy syslog traffic during config_reload under CPU stress.

Documentation

N/A

mssonicbld · 2026-03-25T05:36:00Z

/azp run

azure-pipelines · 2026-03-25T05:36:13Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-25T05:51:40Z

/azp run

azure-pipelines · 2026-03-25T05:51:53Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-25T05:55:38Z

/azp run

azure-pipelines · 2026-03-25T05:55:50Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-25T09:16:25Z

/azp run

azure-pipelines · 2026-03-25T09:16:40Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-25T10:16:03Z

/azp run

azure-pipelines · 2026-03-25T10:16:09Z

Azure Pipelines will not run the associated pipelines, because the pull request was updated after the run command was issued. Review the pull request again and issue a new run command.

linux-foundation-easycla · 2026-03-25T10:16:43Z

The committers listed above are authorized under a signed CLA.

✅ login: Pterosaur / name: Ze Gan (6d05153)

mssonicbld · 2026-03-25T10:24:23Z

/azp run

azure-pipelines · 2026-03-25T10:24:37Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-25T13:41:11Z

/azp run

azure-pipelines · 2026-03-25T13:41:26Z

Azure Pipelines successfully started running 1 pipeline(s).

The test_po_cleanup_after_reload test fails with: RuntimeError: cannot find marker end-LogAnalyzer-... in /var/log/syslog Root cause: two issues combine to lose the loganalyzer end marker. 1. The system logrotate timer can fire mid-test while config_reload is generating heavy syslog traffic under CPU stress. When logrotate rotates /var/log/syslog, loganalyzer markers can be pushed beyond syslog.1 into compressed archives (syslog.2.gz) that are not searched by the marker polling logic. 2. Under heavy CPU load (all cores running 'yes'), the host rsyslogd cannot keep up with the syslog traffic and its UDP receive buffer overflows, silently dropping the end marker written via /dev/log. Fix: - Wrap with DisableLogrotateCronContext to stop the logrotate timer and cron job for the duration of the test. - Move 'kill yes' into a try/finally block inside 'with loganalyzer' so CPU stress is removed before loganalyzer __exit__ places the end marker. - After stopping CPU stress, poll /var/log/syslog file size until it stabilizes (two consecutive 10s intervals with no growth), ensuring rsyslogd has drained the socket buffer backlog before the end marker is placed. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Signed-off-by: Ze Gan <ganze718@gmail.com>

mssonicbld · 2026-03-25T14:14:51Z

/azp run

azure-pipelines · 2026-03-25T14:15:06Z

Azure Pipelines successfully started running 1 pipeline(s).

yxieca

AI agent on behalf of Ying. Reviewed; no issues found.

…PU stress Cherry-pick upstream stop rsyslogd (PR sonic-net#20327 + sonic-net#20969) and add try/finally to ensure CPU stress cleanup + rsyslogd flush before loganalyzer places end marker. Changes: 1. Stop rsyslogd in swss container before config_reload (reduces syslog flood) 2. Use try/finally inside with loganalyzer: to ensure cleanup runs even if config_reload fails 3. Kill CPU stress + flush rsyslogd + sleep 30s before loganalyzer __exit__ places end marker Tested on: vms70-t1-sn5640-3 (str4-sn5640-3, SN5640, 16 CPU, 448 port channels) - PASSED Upstream PR: sonic-net#23291

…PU stress ### Description Fix `test_po_cleanup_after_reload` failure caused by LogAnalyzer end marker being lost under heavy CPU stress and syslog load. ``` RuntimeError: cannot find marker end-LogAnalyzer-port_channel_cleanup.xxx in /var/log/syslog ``` ### Root Cause Two issues combine to lose the loganalyzer end marker: 1. **Logrotate fires mid-test**: The system logrotate timer can trigger during config_reload under CPU stress, rotating `/var/log/syslog`. Markers get pushed beyond `syslog.1` into compressed archives (`syslog.2.gz`) that loganalyzer does not search. 2. **Syslog UDP buffer overflow**: Under heavy CPU load (all cores running `yes`), rsyslogd cannot keep up with syslog traffic and its UDP receive buffer overflows, silently dropping the end marker written via `/dev/log`. ### Fix - Wrap with `DisableLogrotateCronContext` to stop logrotate timer/cron during the test. - Move CPU stress cleanup (`killall yes`) into a `try/finally` block inside `with loganalyzer:` so it runs before `__exit__` places the end marker. - After stopping CPU stress, poll `/var/log/syslog` file size until stable (two consecutive 10s intervals with no growth), ensuring rsyslogd has drained the socket buffer backlog. ### Verification Tested on `vms70-t1-sn5640-3`: **PASSED** (1 passed in 1320s) Upstream PR: sonic-net#23291 ---- #### AI description (iteration 1) #### PR Classification Bug fix in test automation to prevent loganalyzer marker loss under heavy CPU load. #### PR Summary This pull request updates the test for config reload under CPU stress by disabling logrotate and ensuring the loganalyzer markers are preserved during high syslog activity. - In `/tests/pc/test_po_cleanup.py`, a `DisableLogrotateCronContext` is used to prevent log rotation from interfering with marker placement. - The test now includes a try-finally block that kills the CPU stress process and waits for the system log to stabilize before completing. - The imports are updated to include `DisableLogrotateCronContext` and the standard `time` module for the polling mechanism.

mssonicbld · 2026-03-26T09:23:49Z

/azp run

azure-pipelines · 2026-03-26T09:24:03Z

Azure Pipelines successfully started running 1 pipeline(s).

mssonicbld · 2026-03-26T10:14:31Z

/azp run

azure-pipelines · 2026-03-26T10:14:44Z

Azure Pipelines successfully started running 1 pipeline(s).

Signed-off-by: Ze Gan <ganze718@gmail.com>

mssonicbld · 2026-03-26T10:16:54Z

/azp run

azure-pipelines · 2026-03-26T10:17:10Z

Azure Pipelines successfully started running 1 pipeline(s).

#1090) ### Description of PR Backport of sonic-net/sonic-mgmt#23291 to msft-202412. Fix `test_po_cleanup_after_reload` failure caused by LogAnalyzer end marker being lost under heavy CPU stress and syslog load. ### Type of change - [x] Bug fix - [ ] Testbed and Framework(new/improvement) - [ ] New Test case - [ ] Skipped for non-supported platforms - [x] Test case improvement ### Approach #### What is the motivation for this PR? `test_po_cleanup_after_reload` fails consistently with: ``` RuntimeError: cannot find marker end-LogAnalyzer-port_channel_cleanup.xxx in /var/log/syslog ``` Two issues combine to lose the loganalyzer end marker: 1. **Logrotate fires mid-test**: The system logrotate timer can trigger during `config_reload` under CPU stress, rotating `/var/log/syslog`. Markers get pushed beyond `syslog.1` into compressed archives (`syslog.2.gz`) that loganalyzer does not search. 2. **Syslog UDP buffer overflow**: Under heavy CPU load (all cores running `yes`), rsyslogd cannot keep up with syslog traffic and its UDP receive buffer overflows, silently dropping the end marker written via `/dev/log`. #### How did you do it? Three changes to `test_po_cleanup_after_reload`: 1. **Wrap with `DisableLogrotateCronContext`** — stops the logrotate timer and cron job for the duration of the test, preventing mid-test syslog rotation. 2. **Move CPU stress cleanup into a `try/finally` block inside `with loganalyzer:`** — runs before loganalyzer `__exit__` places the end marker, so rsyslogd is no longer competing for CPU. 3. **Poll `/var/log/syslog` file size until stable** — after stopping CPU stress, wait for two consecutive 10-second intervals with no file growth before allowing the end marker to be placed. This ensures rsyslogd has drained any remaining socket buffer backlog. #### How did you verify/test it? 1. **Without fix:** Test fails consistently with `RuntimeError: cannot find marker end-LogAnalyzer-...` 2. **With fix:** PASSED (1 passed in 1153s / 19:13) #### Any platform specific information? Not platform-specific. ### Documentation N/A Signed-off-by: Ze Gan <ganze718@gmail.com> Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

github-actions bot requested review from ZhaohuiS, saiarcot895 and yejianquan March 25, 2026 05:36

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from f7d3a76 to b2feb6a Compare March 25, 2026 05:51

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from b2feb6a to 1a016b7 Compare March 25, 2026 05:55

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from 1a016b7 to 89b0033 Compare March 25, 2026 09:16

Pterosaur changed the title ~~test_po_cleanup: replace LogAnalyzer with direct syslog grep to fix marker drop~~ test_po_cleanup: fix loganalyzer marker drop under CPU stress Mar 25, 2026

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from 89b0033 to 9a19155 Compare March 25, 2026 10:15

github-actions bot requested review from r12f, sdszhang and wangxin March 25, 2026 10:16

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from 9a19155 to 89b0033 Compare March 25, 2026 10:24

Pterosaur removed request for ZhaohuiS, sdszhang, wangxin and yejianquan March 25, 2026 10:46

Pterosaur added the Request for msft-202412 Branch label Mar 25, 2026

github-actions bot requested a review from ZhaohuiS March 25, 2026 13:40

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from 36c1f96 to c4c3bc4 Compare March 25, 2026 13:41

github-actions bot requested review from sdszhang and wangxin March 25, 2026 13:42

Pterosaur changed the title ~~test_po_cleanup: fix loganalyzer marker drop under CPU stress~~ test_po_cleanup: fix loganalyzer marker loss under CPU stress Mar 25, 2026

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from c4c3bc4 to 8dbc7bc Compare March 25, 2026 14:14

Pterosaur mentioned this pull request Mar 25, 2026

[202412] test_po_cleanup: fix loganalyzer marker loss under CPU stress Azure/sonic-mgmt.msft#1090

Merged

5 tasks

Pterosaur added Created PR to msft-202412 Branch and removed Cherry Pick Conflict_msft-202412 labels Mar 25, 2026

Copilot AI mentioned this pull request Mar 26, 2026

Review PRs opened in the last 48 hours by humans #23330

Draft

yxieca previously approved these changes Mar 26, 2026

View reviewed changes

Pterosaur dismissed yxieca’s stale review via 7b8ce8a March 26, 2026 09:23

mssonicbld added the Cherry Pick Conflict_msft-202412 label Mar 26, 2026

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from 7b8ce8a to a088184 Compare March 26, 2026 10:13

Merge remote-tracking branch 'upstream/master' into fix-branch

6d05153

Signed-off-by: Ze Gan <ganze718@gmail.com>

Pterosaur force-pushed the zegan/fix_po_cleanup_loganalyzer_marker branch from a088184 to 6d05153 Compare March 26, 2026 10:16

Conversation

Pterosaur commented Mar 25, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description of PR

Type of change

Back port request

Approach

What is the motivation for this PR?

How did you do it?

How did you verify/test it?

Any platform specific information?

Documentation

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

linux-foundation-easycla bot commented Mar 25, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

mssonicbld commented Mar 25, 2026

Uh oh!

azure-pipelines bot commented Mar 25, 2026

Uh oh!

yxieca left a comment

Choose a reason for hiding this comment

Uh oh!

mssonicbld commented Mar 26, 2026

Uh oh!

azure-pipelines bot commented Mar 26, 2026

Uh oh!

mssonicbld commented Mar 26, 2026

Uh oh!

azure-pipelines bot commented Mar 26, 2026

Uh oh!

mssonicbld commented Mar 26, 2026

Uh oh!

azure-pipelines bot commented Mar 26, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Pterosaur commented Mar 25, 2026 •

edited

Loading

linux-foundation-easycla bot commented Mar 25, 2026 •

edited

Loading