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

stale read query's slow-log doesn't record the StmtReadTS #45545

Open
crazycs520 opened this issue Jul 25, 2023 · 0 comments
Open

stale read query's slow-log doesn't record the StmtReadTS #45545

crazycs520 opened this issue Jul 25, 2023 · 0 comments
Assignees

Comments

@crazycs520
Copy link
Contributor

crazycs520 commented Jul 25, 2023

Enhancement

Stale-read query without in txn, it'sTxn_start_ts in slow-log is 0, it is not friendly to debug. We may need to record StmtReadTS in Txn_start_ts or use another field to distinct with Txn_start_ts.

Txn_start_ts is importance when investigating slow query.

# Time: 2023-07-25T05:01:38.109851486Z
# Txn_start_ts: 0
# User@Host: root[root] @ 10.0.1.1 [10.0.1.1]
# Conn_ID: 6134008245594882069
# Query_time: 0.011962068
# Parse_time: 0.000072619
# Compile_time: 0.000295058
# Rewrite_time: 0.00006279
# Optimize_time: 0.000132229
# Wait_TS: 0
# Cop_time: 0.007272851 Process_time: 0.000133309 Wait_time: 0.00002725 Request_count: 1 Process_keys: 11 Total_keys: 107 Get_snapshot_time: 0.000 Rocksdb_key_skipped_count: 116 Rocksdb_block_cache_hit_count: 4
# DB: test
# Is_internal: false
# Digest: e606e68eee8d6babf9e89d7a1920256260bad5a433b57b935b889e7d712ab22a
# Stats: t1:443091851964841991[215606;10347]
# Num_cop_tasks: 1
# Cop_proc_avg: 0.000133309 Cop_proc_addr: 10.0.1.9:20161
# Cop_wait_avg: 2.725e-05 Cop_wait_addr: 10.0.1.9:20161
# Mem_max: 22196
# Prepared: false
# Plan_from_cache: false
# Plan_from_binding: false
# Has_more_results: false
# KV_total: 0.007232282
# PD_total: 0
# Backoff_total: 0
# Write_sql_response_total: 0.004133461
# Result_rows: 2
# Succ: true
# IsExplicitTxn: false
# IsSyncStatsFailed: false
# Plan: tidb_decode_plan('1QjwRjAJMTRfMTAJMAkwLjg1CXRlc3QudDEuc2sJMgl0aW1lOjcuMzVtcywgbG9vcHM6MgkyLjg3IEtCCTAgQnl0ZXMKMQkxXzEzEUA4bGUoQ29sdW1uIzYsIDIpHUUAMy5FAAw1LjQ4AUWATi9BCjIJMzNfMTQJMAkxLjA2CXJvd19udW1iZXIoKS0+EU1IIG92ZXIocGFydGl0aW9uIGJ5IBGrCHBrLBUMHHNrIG9yZGVyLiAAbHRzIGRlc2Mgcm93cyBiZXR3ZWVuIGN1cnJlbnQBFQwgYW5kLhAADCkJMTEV+wAyGbYAMwGuAQQECjMlNAA3BbIENTA1NDaJAAAsFZUIdHM6AYEuVwAAMRlXFDIJNS4zMiENMVIYNAkzMV8xNhFfVGRhdGE6VGFibGVSYW5nZVNjYW5fMTUdTgQyOR1OdCwgY29wX3Rhc2s6IHtudW06IDEsIG1heDogNy4yNgEpSHByb2Nfa2V5czogMTEsIHRvdF8BEyQ6IDEzMy4zwrVzCRQcd2FpdDogMjcNEwhycGMhlwVPAQxFHAFUADQBVIBjb3ByX2NhY2hlX2hpdF9yYXRpbzogMC4wMCwgYnVpbGQFkghfZHUFGhhuOiAzLjI0BWs4bWF4X2Rpc3RzcWxfY29uKZgoY3k6IDF9CTMuNzEhGUEmDDUJNDQF9wBfQSgMNTAJdCESFDp0MSwgciEXFDpbMHgzMMICACQ0MzkzOTM1MzYgGT8ALBkLqlAATkoABDJEDUEcMSksIGtlZXBJnhQ6ZmFsc2UpwgRrdiUbBDp7JVEEMHNxaRAxfSwgcyHrNGRldGFpbDoge3RvdGFsJasIZXNzNsEBOhgAKF9zaXplOiAzNzI5JcwEYWwRL0AwNywgZ2V0X3NuYXBzaG90XwV2Iccljahyb2Nrc2RiOiB7a2V5X3NraXBwZWRfY291bnQ6IDExNiwgYmxvY2s6IHtjNewNHjA0fX19CU4vQQlOL0EK')
# Plan_digest: 68d93a0450a10996e3e7130586ce3087944adefb9360740ba24330ef95e26ed4
# Binary_plan: tidb_decode_binary_plan('9gm4CvEJCgdTb3J0XzEwEqgJCgxTZWxlY3Rpb25fMTMSyggKCVdpbmRvd18xNBLzBgoNK2A3Eo0GCg5UYWJsZVJlYWRlcl8xNhLaAwoRCRPQYW5nZVNjYW5fMTUhv6QSa0y/f0ApAVZFmw/z9z8wCzgCQAJKDAoKCgR0ZXN0EgJ0MVK3AXIBNRQ6WzB4MzDCAgAkNDM5MzkzNTM2IBk/ACwZC6pQAE5KAAQyRA1B8FsxKSwga2VlcCBvcmRlcjpmYWxzZWrOAXRpa3ZfdGFzazp7dGltZTowcywgbG9vcHM6MX0sIHNjYW5fZGV0YWlsOiB7dG90YWxfcHJvY2Vzc19rZXlzOiAxMSwgdEIYAChfc2l6ZTogMzcyOREfBGtlBS9EMDcsIGdldF9zbmFwc2hvdF90AXbwPCA3LjLCtXMsIHJvY2tzZGI6IHtrZXlfc2tpcHBlZF9jb3VudDogMTE2LCBibG9jazoge2NhY2hlX2hpdF8NHhQ0fX19cP8RAQQBeBEKJP8BIUFUNkgoN2QyxwEkAUABUhZkYXRhOkL3AQRaFAWVFDcuMjltczEPGDJiyQFjb3ApLDAge251bTogMSwgbWF4Bb4ANgEqDHByb2MR6QAxBfkAXwETGDogMTMzLjMF4Sx0b3Rfd2FpdDogMjcNEwxycGNfEU8BDAV9IRIANAFUEGNvcHJfGe1EcmF0aW86IDAuMDAsIGJ1aWxkBZIIX2R1BRoYbjogMy4yNAVrdG1heF9kaXN0c3FsX2NvbmN1cnJlbmN5OiAxfXDYHS4gARjTr+M+1uByQiABACdB4xwudDEucGssIBEMAHMdDBh0czpkZXNjNTEEMzEBs0lADDJwyCoZWhjUX8CyyvfwYUEgAUABUoIBcm93AfaAYmVyKCktPkNvbHVtbiM2IG92ZXIocGFydGl0aW9uIGJ5FXgAcB14BHNrSccuIAAIdHMgAYw0IHJvd3MgYmV0d2VlbiAJ9QB0ARUMIGFuZC4QAAApGbYAMhm2ADNaQwJIgWK7dIkvdkApVJkAHhEm6z8wAgXJDA9sZSgRvQgsIDIdVQAzGVUMMnDwKy5wARh68hkmjuGEQk0AAAo5ZBmdADUuSAAM/BYYAQ==')
select pk, sk, ts, v, n from (             select pk, sk, ts, v, row_number() over (partition by pk, sk order by ts desc) as n             from t1 as of timestamp now() - interval 5 second where pk = '000000000000000000000000049956' and sk >= '0000' and sk < '0000-0001'         ) as tt where n <= 2 order by sk asc;
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant