Skip to content

fix(grpc): drain all remaining log lines at job completion in StreamLogs#1508

Merged
rapids-bot[bot] merged 7 commits into
mainfrom
fix/stream-logs-drain-on-completion
Jul 2, 2026
Merged

fix(grpc): drain all remaining log lines at job completion in StreamLogs#1508
rapids-bot[bot] merged 7 commits into
mainfrom
fix/stream-logs-drain-on-completion

Conversation

@ramakrishnap-nv

Copy link
Copy Markdown
Collaborator

Summary

  • StreamLogs did a single extra getline after detecting job completion, silently dropping any lines flushed between the last EOF poll and the job-complete marker
  • With multiple final log lines (e.g. "Optimal solution found." followed by "Best objective ..."), only the first was streamed to the client
  • Replace the single read with a drain loop so all buffered lines are sent before the job_complete sentinel

Root cause

test_cli_lp_remote and test_cli_mip_remote both parse the CLI subprocess output for solver status and objective. In remote mode the CLI streams server logs via gRPC. The race: if the solver logs two final lines in quick succession and the job is marked complete before StreamLogs polls again, the old code sent exactly one of those lines and dropped the rest.

The probability scales with I/O load (more xdist workers = more contention = wider race window), which is why it surfaced when experimenting with higher -n values in pytest-xdist.

🤖 Generated with Claude Code

StreamLogs did a single extra getline after detecting job completion,
which silently dropped any lines flushed between the last EOF poll and
the job-complete marker. With multiple final log lines (e.g. "Optimal
solution found." followed by "Best objective ..."), only the first was
sent to the client, leaving the rest unstreamed.

Replace the single read with a drain loop so all buffered lines are
sent before the job_complete sentinel.

Fixes test_cli_lp_remote / test_cli_mip_remote flakiness under xdist
where increased I/O activity widens the race window.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>
@ramakrishnap-nv ramakrishnap-nv requested a review from a team as a code owner July 2, 2026 18:32
@ramakrishnap-nv ramakrishnap-nv requested review from kaatish and mlubin July 2, 2026 18:32
@ramakrishnap-nv ramakrishnap-nv self-assigned this Jul 2, 2026
@ramakrishnap-nv ramakrishnap-nv added non-breaking Introduces a non-breaking change improvement Improves an existing functionality labels Jul 2, 2026
@coderabbitai

coderabbitai Bot commented Jul 2, 2026

Copy link
Copy Markdown

Review Change Stack

Note

Reviews paused

It looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the reviews.auto_review.auto_pause_after_reviewed_commits setting.

Use the following commands to manage reviews:

  • @coderabbitai resume to resume automatic reviews.
  • @coderabbitai review to trigger a single review.

Use the checkboxes below for quick actions:

  • ▶️ Resume reviews
  • 🔍 Trigger review
📝 Walkthrough

Walkthrough

The gRPC server now drains all remaining log lines before sending the completion sentinel, and the client now waits briefly for natural log-stream termination on successful solves before falling back to forced cancellation. The incumbent-callback test also accepts successful runs without get-callback activity.

Changes

Log streaming completion handling

Layer / File(s) Summary
Drain remaining log lines before completion
cpp/src/grpc/server/grpc_service_impl.cpp
The EOF/terminal-state branch now loops through all remaining log lines, updates the resume offset per line, and emits the final job_complete=true sentinel after draining.
Graceful client log shutdown
cpp/src/grpc/client/grpc_client.hpp, cpp/src/grpc/client/grpc_client.cpp
The client adds completion tracking and a drain helper, then uses it in solve_lp and solve_mip when completion polling succeeds, otherwise stopping the stream immediately.
Incumbent callback test handling
python/cuopt/cuopt/tests/linear_programming/test_incumbent_callbacks.py
The test records termination status, accepts feasible or optimal completion, skips when no get-callback fires, and still checks set-callback activity when enabled.

Estimated code review effort: 3 (Moderate) | ~25 minutes

Possibly related issues

Related PRs: None specified.

Suggested labels: None specified.

Suggested reviewers: None specified.

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Title check ✅ Passed The title clearly matches the main change: draining remaining gRPC log lines at job completion.
Description check ✅ Passed The description is directly about the same StreamLogs log-drain fix and explains the bug and behavior change.
Docstring Coverage ✅ Passed No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch fix/stream-logs-drain-on-completion

Comment @coderabbitai help to get the list of available commands.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

🧹 Nitpick comments (1)
cpp/src/grpc/server/grpc_service_impl.cpp (1)

831-832: 📐 Maintainability & Code Quality | 🔵 Trivial | 💤 Low value

Local msg/s shadow the outer-scope variables of the same name.

msg (declared at Line 759) and s (declared at Line 760) are already in scope for this function; redeclaring them here shadows the outer variables and hurts readability, and may trip -Wshadow if enabled.

♻️ Suggested rename
-      std::string msg;
-      JobStatus s = check_job_status(job_id, msg);
-      if (s == JobStatus::COMPLETED || s == JobStatus::FAILED || s == JobStatus::CANCELLED) {
+      std::string term_msg;
+      JobStatus term_status = check_job_status(job_id, term_msg);
+      if (term_status == JobStatus::COMPLETED || term_status == JobStatus::FAILED ||
+          term_status == JobStatus::CANCELLED) {
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@cpp/src/grpc/server/grpc_service_impl.cpp` around lines 831 - 832, The local
declarations of msg and JobStatus s in grpc_service_impl.cpp are shadowing the
existing outer-scope msg and s in the same function, which hurts readability and
may trigger -Wshadow. Update the check_job_status call site in the relevant
grpc_service_impl function to reuse the already-declared variables or rename the
inner ones to distinct identifiers, and keep references consistent where msg and
s are used afterward.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@cpp/src/grpc/server/grpc_service_impl.cpp`:
- Around line 826-848: The drain path in grpc_service_impl::write_log_message
handling should stop immediately on a mid-drain Write() failure instead of
continuing to send more data. Update the loop around the remaining log flush so
that if write_log_message returns false, the method exits without sending the
empty completion sentinel and without returning Status::OK, matching the
existing outer tail-loop behavior and preserving the gRPC stream contract.

---

Nitpick comments:
In `@cpp/src/grpc/server/grpc_service_impl.cpp`:
- Around line 831-832: The local declarations of msg and JobStatus s in
grpc_service_impl.cpp are shadowing the existing outer-scope msg and s in the
same function, which hurts readability and may trigger -Wshadow. Update the
check_job_status call site in the relevant grpc_service_impl function to reuse
the already-declared variables or rename the inner ones to distinct identifiers,
and keep references consistent where msg and s are used afterward.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Enterprise

Run ID: 37bd7323-62d5-43c5-8a98-95cabc1b81dc

📥 Commits

Reviewing files that changed from the base of the PR and between 98fc808 and e261713.

📒 Files selected for processing (1)
  • cpp/src/grpc/server/grpc_service_impl.cpp

Comment thread cpp/src/grpc/server/grpc_service_impl.cpp
Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>
@github-actions

github-actions Bot commented Jul 2, 2026

Copy link
Copy Markdown

CI Test Summary

✅ All 31 test job(s) passed.

- Rename shadowing msg/s to term_msg/term_status to avoid -Wshadow
- Skip job_complete sentinel if Write() fails mid-drain; stream is
  already broken so sending the sentinel would violate gRPC contract

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>
@ramakrishnap-nv

Copy link
Copy Markdown
Collaborator Author

/merge

stop_log_streaming() calls TryCancel() which races against the server's
final log drain: poll_for_completion() returns as soon as the job is
marked complete, then TryCancel() kills the stream before the server has
finished sending remaining lines (e.g. "Best objective …").

Add drain_log_streaming(): polls log_stream_done_ (set when the thread
exits naturally after receiving the job_complete sentinel) for up to 5s,
then falls back to stop_log_streaming(). Use it on the success path in
solve_lp and solve_mip so all final log lines are received before the
stream is torn down.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@cpp/src/grpc/client/grpc_client.cpp`:
- Around line 313-326: drain_log_streaming() currently waits up to kDrainTimeout
even when start_log_streaming() never started a thread because
config_.stream_logs or config_.log_callback is disabled, leaving
log_stream_done_ false by default. Update grpc_client_t::drain_log_streaming()
to detect the no-active-streaming case up front (for example by checking the
same configuration or an explicit active-streaming flag used by
start_log_streaming()/stop_log_streaming()) and return immediately instead of
polling, so the common non-streaming solve path does not incur the 5-second
delay.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Enterprise

Run ID: 37add27f-a952-436b-b192-d1638755ff18

📥 Commits

Reviewing files that changed from the base of the PR and between 4db9e47 and 1977c1c.

📒 Files selected for processing (2)
  • cpp/src/grpc/client/grpc_client.cpp
  • cpp/src/grpc/client/grpc_client.hpp

Comment thread cpp/src/grpc/client/grpc_client.cpp
…olution

test_incumbent_get_set_callback[swath1.mps] fails intermittently with
assert 0 > 0 because swath1.mps is sometimes solved at the root node
(integral LP relaxation or presolve), which produces no branch-and-bound
iterations and therefore never triggers incumbent callbacks.

- Skip gracefully when n_callbacks == 0 instead of failing, with a
  message indicating root-node solve
- Fix the always-true assertion on termination status
  (== FeasibleFound or MILPTerminationStatus.Optimal was always True
  because the or operand is a truthy enum value)

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>
@ramakrishnap-nv ramakrishnap-nv requested a review from a team as a code owner July 2, 2026 20:37
@ramakrishnap-nv ramakrishnap-nv requested a review from Iroy30 July 2, 2026 20:37

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick comments (1)
python/cuopt/cuopt/tests/linear_programming/test_incumbent_callbacks.py (1)

94-102: 🎯 Functional Correctness | 🔵 Trivial | ⚡ Quick win

Skip-on-zero-callbacks weakens regression coverage for the callback feature itself.

Converting the callback-firing assertion into a skip is reasonable given cuOpt can solve MILPs at the root node via primal heuristics without branch-and-bound. But this means a real regression that silently breaks callback wiring (rather than a legitimate root-node solve) would now show up as "skipped" instead of "failed," hiding the very bug this test exists to catch. Consider ensuring at least one dataset in the parametrization is known to require branch-and-bound so callback firing is asserted unconditionally in that case, or track/report skip counts to catch a persistently-skipping suite.

As per path instructions, "if the termination/callback assertions could misclassify valid outcomes ... ask for clarification or suggest tightening assertions to reflect the solver's contract rather than hard-coding expected callback counts."

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@python/cuopt/cuopt/tests/linear_programming/test_incumbent_callbacks.py`
around lines 94 - 102, The current zero-callback skip in
test_incumbent_callbacks weakens coverage for the callback wiring itself. Update
the test around get_callback.n_callbacks and termination so at least one
parametrized case is guaranteed to require branch-and-bound and must assert
callbacks fire, rather than skipping unconditionally when n_callbacks is zero.
If keeping the root-node-friendly case, separate it from a known
branch-and-bound dataset or tighten the assertions to reflect the solver’s
contract so a real callback regression still fails instead of being reported as
a skip.

Source: Path instructions

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Nitpick comments:
In `@python/cuopt/cuopt/tests/linear_programming/test_incumbent_callbacks.py`:
- Around line 94-102: The current zero-callback skip in test_incumbent_callbacks
weakens coverage for the callback wiring itself. Update the test around
get_callback.n_callbacks and termination so at least one parametrized case is
guaranteed to require branch-and-bound and must assert callbacks fire, rather
than skipping unconditionally when n_callbacks is zero. If keeping the
root-node-friendly case, separate it from a known branch-and-bound dataset or
tighten the assertions to reflect the solver’s contract so a real callback
regression still fails instead of being reported as a skip.

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Enterprise

Run ID: 620e5dfd-1701-4d72-aea2-d234f2845107

📥 Commits

Reviewing files that changed from the base of the PR and between 1977c1c and 01d69ba.

📒 Files selected for processing (1)
  • python/cuopt/cuopt/tests/linear_programming/test_incumbent_callbacks.py

drain_log_streaming() polled for up to 5 seconds even when
start_log_streaming() never launched a thread (config_.stream_logs or
config_.log_callback disabled), because log_stream_done_ stays false by
default. Return immediately when log_thread_ is null to avoid the delay
on the common non-streaming solve path.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Ramakrishna Prabhu <ramakrishnap@nvidia.com>
@rapids-bot rapids-bot Bot merged commit fe7348a into main Jul 2, 2026
92 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

improvement Improves an existing functionality non-breaking Introduces a non-breaking change

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants