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.

Sign up for GitHub

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

executor: add metric to trace tikvTxn LockKeys time consume #14189

Merged
merged 3 commits into from
Dec 23, 2019
Merged

executor: add metric to trace tikvTxn LockKeys time consume #14189

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
68b9885
add metric to trace tikvTxn LockKeys time consume
cfzjywxk Dec 23, 2019
8d2d814
reduce bucket
cfzjywxk Dec 23, 2019
6730f23
Merge branch 'master' into wt
sre-bot Dec 23, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 6 additions & 4 deletions kv/kv.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -194,10 +194,12 @@ type Transaction interface {

// LockCtx contains information for LockKeys method.
type LockCtx struct {
Killed *uint32
ForUpdateTS uint64
LockWaitTime int64
WaitStartTime time.Time
Killed *uint32
ForUpdateTS uint64
LockWaitTime int64
WaitStartTime time.Time
PessimisticLockWaited int32
LockTimeWaited time.Duration
}

// Client is used to send request to KV layer.
Expand Down
8 changes: 8 additions & 0 deletions metrics/tikvclient.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -232,4 +232,12 @@ var (
Help: "Bucketed histogram of the txn_heartbeat request duration.",
Buckets: prometheus.ExponentialBuckets(0.001, 2, 18), // 1ms ~ 292s
}, []string{LblType})
TiKVPessimisticLockKeysDuration = prometheus.NewHistogram(
prometheus.HistogramOpts{
Namespace: "tidb",
Subsystem: "tikvclient",
Name: "pessimistic_lock_keys_duration",
Buckets: prometheus.ExponentialBuckets(0.001, 2, 30), // 1ms ~ 1073741s
Copy link
Member

Choose a reason for hiding this comment

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

The buckets can fewer.

Help: "tidb txn pessimistic lock keys duration",
})
)
1 change: 1 addition & 0 deletions store/tikv/2pc.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -767,6 +767,7 @@ func (action actionPessimisticLock) handleSingleBatch(c *twoPhaseCommitter, bo *
return ErrLockWaitTimeout
}
}
atomic.StoreInt32(&action.LockCtx.PessimisticLockWaited, 1)
}

// Handle the killed flag when waiting for the pessimistic lock.
Expand Down
11 changes: 10 additions & 1 deletion store/tikv/txn.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -369,6 +369,15 @@ func (txn *tikvTxn) rollbackPessimisticLocks() error {
// lockWaitTime in ms, except that kv.LockAlwaysWait(0) means always wait lock, kv.LockNowait(-1) means nowait lock
func (txn *tikvTxn) LockKeys(ctx context.Context, lockCtx *kv.LockCtx, keysInput ...kv.Key) error {
// Exclude keys that are already locked.
var err error
defer func() {
if err == nil {
if lockCtx.PessimisticLockWaited > 0 {
lockCtx.LockTimeWaited = time.Since(lockCtx.WaitStartTime)
Copy link
Contributor

Choose a reason for hiding this comment

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

Seems the field LockTimeWaited is unnecessary.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is used for slow query logging in the diff part2

metrics.TiKVPessimisticLockKeysDuration.Observe(lockCtx.LockTimeWaited.Seconds())
}
}
}()
keys := make([][]byte, 0, len(keysInput))
txn.mu.Lock()
for _, key := range keysInput {
Expand Down Expand Up @@ -406,7 +415,7 @@ func (txn *tikvTxn) LockKeys(ctx context.Context, lockCtx *kv.LockCtx, keysInput
// If the number of keys greater than 1, it can be on different region,
// concurrently execute on multiple regions may lead to deadlock.
txn.committer.isFirstLock = len(txn.lockKeys) == 0 && len(keys) == 1
err := txn.committer.pessimisticLockKeys(bo, lockCtx, keys)
err = txn.committer.pessimisticLockKeys(bo, lockCtx, keys)
if lockCtx.Killed != nil {
// If the kill signal is received during waiting for pessimisticLock,
// pessimisticLockKeys would handle the error but it doesn't reset the flag.
Expand Down