Skip to content

Use estimated now in stale ts calculation #44215

@you06

Description

@you06

Enhancement

I'm running sysbench point select with 100ms staleness, and got the following error:

[2023/05/26 14:41:43.843 +08:00] [WARN] [session.go:2196] ["compile SQL failed"] [conn=6024217611514938189] [error="cannot set read timestamp to a future time"] [SQL="SELECT c FROM sbtest9 AS OF TIMESTAMP NOW(6) - INTERVAL 100000 MICROSECOND  WHERE id=?"]
[2023/05/26 14:41:43.843 +08:00] [INFO] [conn.go:1181] ["command dispatched failed"] [conn=6024217611514938189] [connInfo="id:6024217611514938189, addr:192.168.80.1:34542 status:10, collation:latin1_swedish_ci, user:root"] [command=Execute] [status="inTxn:0, autocommit:1"] [sql="SELECT c FROM sbtest9 AS OF TIMESTAMP NOW(6) - INTERVAL 100000 MICROSECOND  WHERE id=?"] [txn_mode=PESSIMISTIC] [timestamp=0] [err="cannot set read timestamp to a future time\ngithub.com/pingcap/tidb/sessionctx.ValidateStaleReadTS\n\t/data/tongmu/workspace/tidb/sessionctx/context.go:258\ngithub.com/pingcap/tidb/sessiontxn/staleread.parseAndValidateAsOf\n\t/data/tongmu/workspace/tidb/sessiontxn/staleread/processor.go:288\ngithub.com/pingcap/tidb/sessiontxn/staleread.(*staleReadProcessor).OnSelectTable.func1\n\t/data/tongmu/workspace/tidb/sessiontxn/staleread/processor.go:171\ngithub.com/pingcap/tidb/sessiontxn/staleread.(*staleReadProcessor).OnExecutePreparedStmt\n\t/data/tongmu/workspace/tidb/sessiontxn/staleread/processor.go:203\ngithub.com/pingcap/tidb/planner/core.(*preprocessor).resolveExecuteStmt\n\t/data/tongmu/workspace/tidb/planner/core/preprocess.go:1654\ngithub.com/pingcap/tidb/planner/core.(*preprocessor).Enter\n\t/data/tongmu/workspace/tidb/planner/core/preprocess.go:253\ngithub.com/pingcap/tidb/parser/ast.(*ExecuteStmt).Accept\n\t/data/tongmu/workspace/tidb/parser/ast/misc.go:564\ngithub.com/pingcap/tidb/planner/core.Preprocess\n\t/data/tongmu/workspace/tidb/planner/core/preprocess.go:136\ngithub.com/pingcap/tidb/executor.(*Compiler).Compile\n\t/data/tongmu/workspace/tidb/executor/compiler.go:81\ngithub.com/pingcap/tidb/session.(*session).ExecuteStmt\n\t/data/tongmu/workspace/tidb/session/session.go:2184\ngithub.com/pingcap/tidb/server.(*TiDBContext).ExecuteStmt\n\t/data/tongmu/workspace/tidb/server/driver_tidb.go:252\ngithub.com/pingcap/tidb/server.(*clientConn).executePreparedStmtAndWriteResult\n\t/data/tongmu/workspace/tidb/server/conn_stmt.go:277\ngithub.com/pingcap/tidb/server.(*clientConn).executePlanCacheStmt\n\t/data/tongmu/workspace/tidb/server/conn_stmt.go:225\ngithub.com/pingcap/tidb/server.(*clientConn).handleStmtExecute\n\t/data/tongmu/workspace/tidb/server/conn_stmt.go:217\ngithub.com/pingcap/tidb/server.(*clientConn).dispatch\n\t/data/tongmu/workspace/tidb/server/conn.go:1430\ngithub.com/pingcap/tidb/server.(*clientConn).Run\n\t/data/tongmu/workspace/tidb/server/conn.go:1152\ngithub.com/pingcap/tidb/server.(*Server).onConn\n\t/data/tongmu/workspace/tidb/server/server.go:648\nruntime.goexit\n\t/data/tongmu/tools/go/go/src/runtime/asm_amd64.s:1598\nSELECT c FROM sbtest9 AS OF TIMESTAMP NOW(6) - INTERVAL 100000 MICROSECOND  WHERE id=?"]

TiDB first calculation the stale ts expr TIMESTAMP NOW(6) - INTERVAL 100000 MICROSECOND, and check it by another ts estimated by last_pd_ts + elapsed, here the function NOW() is drifted forward more than 100ms compare with last_pd_ts + elapsed so this error happens.

We can calculate the function NOW() using last_pd_ts + elapsed, this should be more accurate and reduce staleread miss.

Metadata

Metadata

Assignees

No one assigned

    Labels

    affects-6.5This bug affects the 6.5.x(LTS) versions.type/enhancementThe issue or PR belongs to an enhancement.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions