Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

server: add sql to com_exec/com_fetch dispatch error log #12174

Merged
merged 5 commits into from
Sep 16, 2019
Merged

server: add sql to com_exec/com_fetch dispatch error log #12174

merged 5 commits into from
Sep 16, 2019

Conversation

lysu
Copy link
Contributor

@lysu lysu commented Sep 12, 2019

What problem does this PR solve?

More and more user use prepare stmt, but current dispatch error log we only can see packet binary info, we don't know which sql meet error.

What is changed and how it works?

add sql to error thrown in handleStmtExec and handleStmtFetch

after this PR, we can got

[2019/09/12 15:38:43.715 +08:00] [WARN] [conn.go:669] ["command dispatched failed"] [conn=1] [connInfo="id:1, addr:127.0.0.1:43540 status:2, collation:utf8_general_ci, user:root"] [command=Fetch] [sql="\u0001\u0000\u0000\u0000\u0001\u0000\u0000\u0000"] [err="12121\ngithub.jparrowsec.cn/pingcap/tidb/server.(*clientConn).handleStmtFetch\n\t/home/robi/code/go/src/github.com/pingcap/tidb/server/conn_stmt.go:239\ngithub.jparrowsec.cn/pingcap/tidb/server.(*clientConn).dispatch\n\t/home/robi/code/go/src/github.com/pingcap/tidb/server/conn.go:914\ngithub.jparrowsec.cn/pingcap/tidb/server.(*clientConn).Run\n\t/home/robi/code/go/src/github.com/pingcap/tidb/server/conn.go:653\ngithub.jparrowsec.cn/pingcap/tidb/server.(*Server).onConn\n\t/home/robi/code/go/src/github.com/pingcap/tidb/server/server.go:438\nruntime.goexit\n\t/home/robi/runtime/go/src/runtime/asm_amd64.s:1337\nselect 1"]

("select 1" now is in last, we can modify pingcap/errors to let be in front, but we need add msg first)

Check List

Tests

  • Unit test
  • Integration test

Code changes

  • wrap error message with sql

Side effects

  • N/A

Related changes

  • Need to cherry-pick to the release branch

Release note

  • server: add sql to com_exec/com_fetch dispatch error log

This change is Reviewable

@lysu
Copy link
Contributor Author

lysu commented Sep 12, 2019

/run-all-tests

@lysu lysu requested review from jackysp and tiancaiamao September 12, 2019 07:42
@ngaut
Copy link
Member

ngaut commented Sep 12, 2019

Could you remove the stack error message, it feels like noise.

@codecov
Copy link

codecov bot commented Sep 12, 2019

Codecov Report

Merging #12174 into master will not change coverage.
The diff coverage is n/a.

@@             Coverage Diff             @@
##             master     #12174   +/-   ##
===========================================
  Coverage   81.2778%   81.2778%           
===========================================
  Files           454        454           
  Lines         98290      98290           
===========================================
  Hits          79888      79888           
  Misses        12682      12682           
  Partials       5720       5720

@lysu
Copy link
Contributor Author

lysu commented Sep 12, 2019

Could you remove the stack error message, it feels like noise.

maybe we'd better not remove stack in for this case, stack in "dispatch error" is useful for troubleshooting.

for example, some low-level method returns std error(e.g. DeadlineExceeded) and error goes up to top-level dispatch method return short error to user and write detail dispatch error log, without stack we may hard to identity error is thrown in A or B logic(e.g. pdclient or tikvclient). IMHO, if different components throw the different error is ok, but when different components can throw the same error and we want to log it in one place(like this entrance method), maybe we need stack to identity.

we should let sql in front of stack info.

@lysu
Copy link
Contributor Author

lysu commented Sep 12, 2019

this previous log example is generated by with-stack error.

if we can make sure the error no need stack(e.g. KeyDuplicateError) we can use errors.SuspendStack to foribid stack for special error, fot that error, log will be

[conn.go:669] ["command dispatched failed"] [conn=1] [connInfo="id:1, addr:127.0.0.1:45114 status:2, collation:utf8_general_ci, user:root"] [command=Fetch] [sql="\u0001\u0000\u0000\u0000\u0001\u0000\u0000\u0000"] [err="12121\nselect 1"]

server/conn_stmt.go Outdated Show resolved Hide resolved
Copy link
Member

@jackysp jackysp left a comment

Choose a reason for hiding this comment

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

LGTM

@tiancaiamao
Copy link
Contributor

LGTM

@tiancaiamao tiancaiamao added the status/LGT2 Indicates that a PR has LGTM 2. label Sep 16, 2019
@lysu lysu added needs-cherry-pick-2.1 status/can-merge Indicates a PR has been approved by a committer. labels Sep 16, 2019
@sre-bot
Copy link
Contributor

sre-bot commented Sep 16, 2019

/run-all-tests

@sre-bot
Copy link
Contributor

sre-bot commented Sep 16, 2019

cherry pick to release-3.1 in PR #12189

@sre-bot
Copy link
Contributor

sre-bot commented Sep 16, 2019

cherry pick to release-3.0 in PR #12191

@lysu
Copy link
Contributor Author

lysu commented Sep 26, 2019

/run-cherry-picker

@sre-bot
Copy link
Contributor

sre-bot commented Sep 26, 2019

cherry pick to release-2.1 failed

@sre-bot
Copy link
Contributor

sre-bot commented Apr 7, 2020

It seems that, not for sure, we failed to cherry-pick this commit to release-2.1. Please comment '/run-cherry-picker' to try to trigger the cherry-picker if we did fail to cherry-pick this commit before. @lysu PTAL.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
component/server status/can-merge Indicates a PR has been approved by a committer. status/LGT2 Indicates that a PR has LGTM 2. type/usability
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants