server: fix inaccurate WriteSQLRespDuration#69536
Conversation
ti-chi-bot
Bot
added
release-note-none
|
[APPROVALNOTIFIER] This PR is NOT APPROVED This pull-request has been approved by: The full list of commands accepted by this bot can be found here. DetailsNeeds approval from an approver in each of these files:Approvers can indicate their approval by writing |
|
Note Reviews pausedIt 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 Use the following commands to manage reviews:
Use the checkboxes below for quick actions:
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Repository UI Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (1)
📝 WalkthroughWalkthroughThis PR refactors WriteSQLRespDuration accounting in server connection handling. It adds shared context/timing helpers, splits response-write timing into smaller segments in result-set paths, and adds a test that checks failed writes are counted in the duration metric. ChangesSQL response duration timing refactor
Estimated code review effort: 3 (Moderate) | ~25 minutes Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (2)
pkg/server/conn.go (2)
1281-1339: 🎯 Functional Correctness | 🟠 Major | 🏗️ Heavy liftPreserve delayed finalization on every dispatch-error exit.
Line 1339 runs after the
io.EOF/ result-undetermined early returns, so a delayed no-result statement can skipFinishExecuteStmtentirely on those exits. Also,writeError(ctx, err)uses the Run-loop context, while the per-statement execdetails context is created insidehandleStmt, so error-packet write time may still not be charged before finalization. Move delayed finalization into the early-return paths and make the error response write use the statement execdetails context/state.🤖 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 `@pkg/server/conn.go` around lines 1281 - 1339, The dispatch-error handling in conn.go can skip delayed statement finalization on the io.EOF and result-undetermined early returns, so make sure FinishExecuteStmt-equivalent delayed cleanup via cc.finishDelayedNoResultStmt is executed in those branches too. Also, update the error-packet write path around cc.writeError and handleStmt/execdetails so it uses the per-statement execdetails context/state instead of the outer Run-loop ctx, ensuring write time is charged before finalization.
2720-2754: 🎯 Functional Correctness | 🟠 Major | ⚡ Quick winDo not include cursor fetch time in WriteSQLRespDuration.
Line 2720 starts timing before the fetch loop, but line 2739 can advance a lazy iterator and call
rs.Next, so executor fetch time is accumulated as response-write time. Keep the timer scoped to row serialization / packet writes, matchingwriteChunks.Proposed fix
- start = beginWriteSQLRespDuration(stmtDetail) - iter := rs.GetRowIterator() // send the rows to the client according to fetchSize. for i := 0; i < fetchSize && iter.Current(ctx) != iter.End(); i++ { row := iter.Current(ctx) + start = beginWriteSQLRespDuration(stmtDetail) data = data[0:4] data, err = column.DumpBinaryRow(data, rs.Columns(), row, cc.rsEncoder) if err != nil { addWriteSQLRespDuration(stmtDetail, start) return err @@ addWriteSQLRespDuration(stmtDetail, start) return err } + addWriteSQLRespDuration(stmtDetail, start) writtenRows++ iter.Next(ctx) } if iter.Error() != nil { - addWriteSQLRespDuration(stmtDetail, start) return iter.Error() } @@ // don't include the time consumed by `cl.OnFetchReturned()` in the `WriteSQLRespDuration` - addWriteSQLRespDuration(stmtDetail, start) -🤖 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 `@pkg/server/conn.go` around lines 2720 - 2754, The COM_STMT_FETCH path in `handleFetch` is counting cursor execution time in `WriteSQLRespDuration` because `beginWriteSQLRespDuration(stmtDetail)` starts before the row loop and `iter.Next(ctx)` may trigger lazy fetch work. Move the timing scope so it covers only row serialization and `cc.writePacket` calls, and keep the final `addWriteSQLRespDuration(stmtDetail, start)` updates aligned with the new scope, matching the behavior in `writeChunks`.
🤖 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 `@pkg/server/conn.go`:
- Around line 2362-2367: The delayed finalization in
cc.handleFileTransInConn/finishDelayedNoResultStmt is dropping a write failure
when handled is false, because the else branch passes nil and clears
ExecStmtVarKey. Update the fallback path in the Run-loop flow so the actual err
from handleFileTransInConn is forwarded into finishDelayedNoResultStmt for both
handled and unhandled cases, preserving the no-result write error for later
summary/log handling.
---
Outside diff comments:
In `@pkg/server/conn.go`:
- Around line 1281-1339: The dispatch-error handling in conn.go can skip delayed
statement finalization on the io.EOF and result-undetermined early returns, so
make sure FinishExecuteStmt-equivalent delayed cleanup via
cc.finishDelayedNoResultStmt is executed in those branches too. Also, update the
error-packet write path around cc.writeError and handleStmt/execdetails so it
uses the per-statement execdetails context/state instead of the outer Run-loop
ctx, ensuring write time is charged before finalization.
- Around line 2720-2754: The COM_STMT_FETCH path in `handleFetch` is counting
cursor execution time in `WriteSQLRespDuration` because
`beginWriteSQLRespDuration(stmtDetail)` starts before the row loop and
`iter.Next(ctx)` may trigger lazy fetch work. Move the timing scope so it covers
only row serialization and `cc.writePacket` calls, and keep the final
`addWriteSQLRespDuration(stmtDetail, start)` updates aligned with the new scope,
matching the behavior in `writeChunks`.
🪄 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: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: 67c5ab38-4f34-4544-b61a-dae7680f2191
📒 Files selected for processing (4)
pkg/server/conn.gopkg/server/conn_stmt.gopkg/server/conn_stmt_test.gopkg/session/session.go
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## master #69536 +/- ##
================================================
- Coverage 76.3169% 74.3324% -1.9846%
================================================
Files 2041 2045 +4
Lines 561123 578087 +16964
================================================
+ Hits 428232 429706 +1474
- Misses 131990 147836 +15846
+ Partials 901 545 -356
Flags with carried forward coverage won't be shown. Click here to find out more.
🚀 New features to boost your workflow:
|
ChangRui-Ryan
force-pushed
the
changrui_resp_time
branch
from
e29e2c9 to
0fcdbc9
Compare
ti-chi-bot
Bot
added
size/L
There was a problem hiding this comment.
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
pkg/server/conn.go (1)
2668-2725: 🎯 Functional Correctness | 🟡 Minor | ⚡ Quick winScope
WriteSQLRespDurationto the dump/write path only. WithlazyRowIterator, the firstCurrent(ctx)and eachNext(ctx)can callrs.Next(ctx, chk), so the current window counts executor fetch time as response-write time.writeChunkskeeps fetch outside that window; this path should do the same by timing onlyDumpBinaryRow/writePacket.🤖 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 `@pkg/server/conn.go` around lines 2668 - 2725, `writeChunksWithFetchSize` is counting lazy iterator fetch work inside `WriteSQLRespDuration` because `iter.Current(ctx)` and `iter.Next(ctx)` may trigger `rs.Next(ctx, chk)`. Move the timing window in `clientConn.writeChunksWithFetchSize` so it only covers the `DumpBinaryRow` and `writePacket` path, matching `writeChunks` and excluding executor fetch time; keep the existing EOF/notification handling outside that measured span.
🧹 Nitpick comments (1)
pkg/server/conn_stmt_test.go (1)
219-224: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winDocument the magic
failOnWrite: 4value.The buffer size of 1 forces byte-level flushing, so
failOnWrite: 4is implicitly tied to the exact wire-protocol byte layout (column info + row packet bytes) at the time this test was written. If packet-writing internals change later, this could silently target the wrong write (e.g., before column info completes) without an obvious failure signal. A short comment explaining what the 4th write corresponds to would make the test easier to maintain.💡 Suggested comment
const delay = 50 * time.Millisecond + // failOnWrite=4 targets a byte write that occurs mid row-data write (after + // column info is flushed), so the failure happens during actual row + // transmission and WriteSQLRespDuration should include the delay. c.pkt.SetBufWriter(bufio.NewWriterSize(&failedWriteResponseWriter{ delay: delay, failOnWrite: 4, }, 1))🤖 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 `@pkg/server/conn_stmt_test.go` around lines 219 - 224, The test in conn_stmt_test uses a magic failOnWrite value that is tied to the current packet write sequence. Add a brief explanatory comment near the failedWriteResponseWriter setup in conn_stmt_test clarifying what the 4th write represents in the query response flow, so future changes to the wire protocol or buffering behavior do not make the test’s intent unclear. Refer to the c.Dispatch path and failedWriteResponseWriter setup when placing the comment.
🤖 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.
Outside diff comments:
In `@pkg/server/conn.go`:
- Around line 2668-2725: `writeChunksWithFetchSize` is counting lazy iterator
fetch work inside `WriteSQLRespDuration` because `iter.Current(ctx)` and
`iter.Next(ctx)` may trigger `rs.Next(ctx, chk)`. Move the timing window in
`clientConn.writeChunksWithFetchSize` so it only covers the `DumpBinaryRow` and
`writePacket` path, matching `writeChunks` and excluding executor fetch time;
keep the existing EOF/notification handling outside that measured span.
---
Nitpick comments:
In `@pkg/server/conn_stmt_test.go`:
- Around line 219-224: The test in conn_stmt_test uses a magic failOnWrite value
that is tied to the current packet write sequence. Add a brief explanatory
comment near the failedWriteResponseWriter setup in conn_stmt_test clarifying
what the 4th write represents in the query response flow, so future changes to
the wire protocol or buffering behavior do not make the test’s intent unclear.
Refer to the c.Dispatch path and failedWriteResponseWriter setup when placing
the comment.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: add73d87-c4f4-4215-9e60-8144261c5988
📒 Files selected for processing (2)
pkg/server/conn.gopkg/server/conn_stmt_test.go
1 participant
What problem does this PR solve?
Issue Number: close #64562
Problem Summary
WriteSQLRespDurationmay be inaccurate forSELECTstatements when writing the result set response fails. Some error paths in result set writing returned immediately afterwritePacket/writeEOF/ related write operations failed, before adding the elapsed response write time to statement execution details.What changed and how does it work
This PR updates the result set response writing paths to always record elapsed write time before returning, including failure paths. It adds small helper functions to start and accumulate
WriteSQLRespDuration, then uses them inwriteChunksandwriteChunksWithFetchSizesoSELECTresult set writes and cursor fetch writes include time spent before a write error. A regression test simulates a failed row packet write for a normalSELECTand verifies the delayed write time is reflected inWriteSQLRespDuration.Check List
Tests
Side effects
Documentation
Release note
Please refer to Release Notes Language Style Guide to write a quality release note.
Summary by CodeRabbit