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

use context logger as much as possible #908

Merged
merged 5 commits into from
Jul 31, 2023
Merged

Conversation

crazycs520
Copy link
Contributor

Use Logger(ctx) instead of BgLogger as much as possible.

Since Logger(ctx) maybe contain other information such as connection id, which is good for debug.

Here are some log before this PR:

[2023/07/25 16:02:19.812 +08:00] [WARN] [region_request.go:612] ["unable to find stores with given labels"] [labels="[{\"key\":\"zone\",\"value\":\"z99\"}]"]
[2023/07/25 16:01:34.877 +08:00] [WARN] [region_request.go:1942] ["tikv reports `DataIsNotReady` retry later"] [store-id=4] [peer-id=8008] [region-id=1011] [safe-ts=443094687287869442] [ctx="region ID: 1011, meta: id:1011 start_key:\"t\\200\\000\\000\\000\\000\\000\\000`_r\\00100000000\\37700000000\\37700000000\\377051486\\000\\000\\375\\0010000-000\\3771\\000\\000\\000\\000\\000\\000\\000\\370\\003\\227s\\332eMU\\256\\350\" end_key:\"x\\000\\000\\000\" region_epoch:<conf_ver:77 version:63 > peers:<id:8006 store_id:1 > peers:<id:8007 store_id:14 > peers:<id:8008 store_id:4 > , peer: id:8008 store_id:4 , addr: 10.0.1.9:22160, idx: 0, reqStoreType: TiKvOnly, runStoreType: tikv"]
[2023/07/25 16:05:33.038 +08:00] [WARN] [backoff.go:158] ["regionMiss backoffer.maxSleep 40000ms is exceeded, errors:\nepoch_not_match:<>  at 2023-07-25T16:05:30.479434+08:00\nsend tikv request error: no available connections, ctx: region ID: 7034, meta: id:7034 start_key:\"r\\000\\000\\001\" end_key:\"t\\200\\000\\000\\000\\000\\000\\000`_r\\00100000000\\37700000000\\37700000000\\377051486\\000\\000\\375\\0010000-000\\3771\\000\\000\\000\\000\\000\\000\\000\\370\\003\\227s\\332eMU\\256\\350\" region_epoch:<conf_ver:59 version:63 > peers:<id:7035 store_id:7 > peers:<id:7036 store_id:3 > peers:<id:8002 store_id:2 > , peer: id:7036 store_id:3 , addr: 10.0.1.9:21161, idx: 0, reqStoreType: TiKvOnly, runStoreType: tikv, try next peer later at 2023-07-25T16:05:30.99473+08:00\nepoch_not_match:<>  at 2023-07-25T16:05:32.538+08:00\nlongest sleep type: tikvRPC, time: 23808ms"]

In this PR and pingcap/tidb#45559, those logs will contain conn information such as following:

[2023/07/25 15:47:36.507 +08:00] [WARN] [region_request.go:612] ["unable to find stores with given labels"] [conn=5901628662087680005] [labels="[{\"key\":\"zone\",\"value\":\"z99\"}]"]
[2023/07/25 15:46:44.936 +08:00] [WARN] [region_request.go:1942] ["tikv reports `DataIsNotReady` retry later"] [conn=5901628662087680005] [store-id=1] [peer-id=8006] [region-id=1011] [safe-ts=443094453573386242] [ctx="region ID: 1011, meta: id:1011 start_key:\"t\\200\\000\\000\\000\\000\\000\\000`_r\\00100000000\\37700000000\\37700000000\\377051486\\000\\000\\375\\0010000-000\\3771\\000\\000\\000\\000\\000\\000\\000\\370\\003\\227s\\332eMU\\256\\350\" end_key:\"x\\000\\000\\000\" region_epoch:<conf_ver:77 version:63 > peers:<id:8006 store_id:1 > peers:<id:8007 store_id:14 > peers:<id:8008 store_id:4 > , peer: id:8006 store_id:1 , addr: 10.0.1.9:21160, idx: 0, reqStoreType: TiKvOnly, runStoreType: tikv"]
[2023/07/25 15:49:01.169 +08:00] [WARN] [backoff.go:158] ["tikvRPC backoffer.maxSleep 40000ms is exceeded, errors:\nregion_id:1011, region_ver:63, store_type:tikv, peer_addr:10.0.1.9:21160, error:epoch_not_match:<>  at 2023-07-25T15:48:58.418795+08:00\nsend tikv request error: no available connections, ctx: region ID: 1011, meta: id:1011 start_key:\"t\\200\\000\\000\\000\\000\\000\\000`_r\\00100000000\\37700000000\\37700000000\\377051486\\000\\000\\375\\0010000-000\\3771\\000\\000\\000\\000\\000\\000\\000\\370\\003\\227s\\332eMU\\256\\350\" end_key:\"x\\000\\000\\000\" region_epoch:<conf_ver:77 version:63 > peers:<id:8006 store_id:1 > peers:<id:8007 store_id:14 > peers:<id:8008 store_id:4 > , peer: id:8006 store_id:1 , addr: 10.0.1.9:21160, idx: 0, reqStoreType: TiKvOnly, runStoreType: tikv, try next peer later at 2023-07-25T15:48:59.05543+08:00\nregion_id:1011, region_ver:63, store_type:tikv, peer_addr:10.0.1.9:21160, error:epoch_not_match:<>  at 2023-07-25T15:49:00.530693+08:00\nlongest sleep type: tikvRPC, time: 31516ms"] [conn=5901628662087680005]

Signed-off-by: crazycs520 <crazycs520@gmail.com>
Signed-off-by: crazycs520 <crazycs520@gmail.com>
@crazycs520 crazycs520 marked this pull request as ready for review July 25, 2023 08:15
@cfzjywxk
Copy link
Contributor

@crazycs520
Need to re-run the test.

@cfzjywxk cfzjywxk requested review from zyguan, you06 and ekexium July 26, 2023 07:36
@cfzjywxk cfzjywxk merged commit 719e645 into tikv:master Jul 31, 2023
crazycs520 added a commit to crazycs520/client-go that referenced this pull request Aug 7, 2023
* use context logger as much as possible

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* refine

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>
iosmanthus added a commit that referenced this pull request Aug 11, 2023
* client-go: add some key range info to error when PD returned no region (#862)

Signed-off-by: Chao Wang <cclcwangchao@hotmail.com>

* *: refine non-global stale-read request retry logic (#863)

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* Fix the issue that primary pessimistic lock may be left not cleared after GC (#866)

* Fix the issue that primary pessimistic lock may be left not cleared after GC

Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>

* Fix mysteriously shown up thing that makes compilation failed

Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>

* Fix test effectiveness (forgot to set txn2 to pessimistic txn); add more strict checks

Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>

* Address comments

Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>

---------

Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>
Co-authored-by: MyonKeminta <MyonKeminta@users.noreply.github.com>

* add explicit request source type to label the external request like lightning/br (#868)

Signed-off-by: nolouch <nolouch@gmail.com>

* use '%d' instead of '%q' for some int values in error message (#875)

Signed-off-by: Chao Wang <cclcwangchao@hotmail.com>

* format key in error message in method `scanRegions` (#876)

Signed-off-by: Chao Wang <cclcwangchao@hotmail.com>

* make cop request timeout a config paramter (#865)

* update

Signed-off-by: Spade A <u6748471@anu.edu.au>

* update

Signed-off-by: Spade A <u6748471@anu.edu.au>

* update

Signed-off-by: Spade A <u6748471@anu.edu.au>

* update

Signed-off-by: Spade A <u6748471@anu.edu.au>

---------

Signed-off-by: Spade A <u6748471@anu.edu.au>

* region_cache: support check pending tiflash peer (#821)

Signed-off-by: guo-shaoge <shaoge1994@163.com>
Co-authored-by: disksing <i@disksing.com>

* *: add `SnapshotIterReverse` and make `iterReverse` supports `lowerBound` (#883)

Signed-off-by: Jason Mo <mohangjie1995@gmail.com>

* *: fix stale read ops metric (#878) (#889)

Signed-off-by: crazycs520 <crazycs520@gmail.com>
Co-authored-by: disksing <i@disksing.com>

* add gc options (#828)

Signed-off-by: weedge <weege007@gmail.com>
Co-authored-by: disksing <i@disksing.com>

* reload region cache when store is resolved from invalid status (#843)

Signed-off-by: you06 <you1474600@gmail.com>
Co-authored-by: disksing <i@disksing.com>

* ci: update setup-go action (#904)

Signed-off-by: disksing <i@disksing.com>

* fix unexpected slow query during GC running after stop 1 tikv-server (#899) (#909)

* fix unexpected slow query during GC running after stop 1 tikv-server

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix test

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* resource_manager: ignore ru metrics for background request (#872)

Signed-off-by: husharp <jinhao.hu@pingcap.com>
Co-authored-by: disksing <i@disksing.com>

* add more log for diagnose (#915)

* add more log for diagnose

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* add more log for diagnose

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* add more log

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* address comment

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* use context logger as much as possible (#908)

* use context logger as much as possible

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* refine

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* Resume max retry time check for stale read retry with leader option(#903) (#911)

* Resume max retry time check for stale read retry with leader option

Signed-off-by: cfzjywxk <lsswxrxr@163.com>

* add cancel

Signed-off-by: cfzjywxk <lsswxrxr@163.com>

---------

Signed-off-by: cfzjywxk <lsswxrxr@163.com>

* request_source: remove default label (#890)

* request_source: remove default label

Signed-off-by: nolouch <nolouch@gmail.com>

* add a function to set request source task type (#925)

* add a function to set request source task type

Signed-off-by: glorv <glorvs@163.com>

* ci: update go version (#936)

* ci: update go version

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix test

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* use tidb_kv_read_timeout as first kv request timeout (#919)

* support tidb_kv_read_timeout as first round kv request timeout

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix ci

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix ci

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix ci

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix ci

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* fix ci

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* update comment

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* refine test

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* [pick] resource_control: bypass some internal urgent request (#938)

* resource_control: bypass some internal urgent request (#884)

Signed-off-by: nolouch <nolouch@gmail.com>

* resourcecontrol: fix nil pointer (#900)

Signed-off-by: nolouch <nolouch@gmail.com>

---------

Signed-off-by: nolouch <nolouch@gmail.com>

---------

Signed-off-by: Chao Wang <cclcwangchao@hotmail.com>
Signed-off-by: crazycs520 <crazycs520@gmail.com>
Signed-off-by: MyonKeminta <MyonKeminta@users.noreply.github.com>
Signed-off-by: nolouch <nolouch@gmail.com>
Signed-off-by: Spade A <u6748471@anu.edu.au>
Signed-off-by: guo-shaoge <shaoge1994@163.com>
Signed-off-by: Jason Mo <mohangjie1995@gmail.com>
Signed-off-by: weedge <weege007@gmail.com>
Signed-off-by: you06 <you1474600@gmail.com>
Signed-off-by: disksing <i@disksing.com>
Signed-off-by: husharp <jinhao.hu@pingcap.com>
Signed-off-by: cfzjywxk <lsswxrxr@163.com>
Signed-off-by: glorv <glorvs@163.com>
Signed-off-by: iosmanthus <myosmanthustree@gmail.com>
Co-authored-by: 王超 <cclcwangchao@hotmail.com>
Co-authored-by: crazycs <crazycs520@gmail.com>
Co-authored-by: MyonKeminta <9948422+MyonKeminta@users.noreply.github.com>
Co-authored-by: MyonKeminta <MyonKeminta@users.noreply.github.com>
Co-authored-by: ShuNing <nolouch@gmail.com>
Co-authored-by: Spade  A <71589810+SpadeA-Tang@users.noreply.github.com>
Co-authored-by: guo-shaoge <shaoge1994@163.com>
Co-authored-by: disksing <i@disksing.com>
Co-authored-by: Hangjie Mo <mohangjie1995@gmail.com>
Co-authored-by: weedge <weege007@gmail.com>
Co-authored-by: you06 <you1474600@gmail.com>
Co-authored-by: Hu# <jinhao.hu@pingcap.com>
Co-authored-by: cfzjywxk <lsswxrxr@163.com>
Co-authored-by: glorv <glorvs@163.com>
cfzjywxk pushed a commit that referenced this pull request Aug 15, 2023
* use context logger as much as possible



* refine



---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>
crazycs520 added a commit to crazycs520/client-go that referenced this pull request May 15, 2024
Signed-off-by: crazycs520 <crazycs520@gmail.com>
cfzjywxk pushed a commit that referenced this pull request May 21, 2024
* improve region request log for diagnose

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* remove useless filed

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* use context logger as much as possible (#908)

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* add leader peer id log

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* *: fix panic in get cause error (#1344)

Signed-off-by: crazycs520 <crazycs520@gmail.com>

* address comment

Signed-off-by: crazycs520 <crazycs520@gmail.com>

---------

Signed-off-by: crazycs520 <crazycs520@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants