diff --git a/src/tendisplus/commands/command.cpp b/src/tendisplus/commands/command.cpp index 20ee53bd..5bb9b1b5 100644 --- a/src/tendisplus/commands/command.cpp +++ b/src/tendisplus/commands/command.cpp @@ -383,6 +383,7 @@ Expected Command::runSessionCmd(Session* sess) { sess->getCtx()->setArgsBrief(sess->getArgs()); it->second->incrCallTimes(); auto now = nsSinceEpoch(); + sess->resetLockWaitTime(); auto guard = MakeGuard([it, now, sess, commandName] { sess->getCtx()->clearRequestCtx(); auto end = nsSinceEpoch(); diff --git a/src/tendisplus/server/segment_manager.cpp b/src/tendisplus/server/segment_manager.cpp index b4af29cd..85185c26 100644 --- a/src/tendisplus/server/segment_manager.cpp +++ b/src/tendisplus/server/segment_manager.cpp @@ -108,6 +108,7 @@ Expected SegmentMgrFnvHash64::getDbWithKeyLock( } if (mode != mgl::LockMode::LOCK_NONE) { + auto start = nsSinceEpoch(); auto elk = KeyLock::AquireKeyLock(segId, chunkId, key, @@ -115,6 +116,8 @@ Expected SegmentMgrFnvHash64::getDbWithKeyLock( sess, sess->getServerEntry()->getMGLockMgr(), lockTimeoutMs); + auto duration = nsSinceEpoch() - start; + sess->addLockWaitTime(duration); if (!elk.ok()) { return elk.status(); } diff --git a/src/tendisplus/server/server_entry.cpp b/src/tendisplus/server/server_entry.cpp index f3b02ca6..ed5f8389 100644 --- a/src/tendisplus/server/server_entry.cpp +++ b/src/tendisplus/server/server_entry.cpp @@ -259,6 +259,7 @@ void SlowlogStat::slowlogDataPushEntryIfNeeded( slowLog << "# Db: " << sess->getCtx()->getDbId() << "\n"; slowLog << "# Query_time: " << duration << "\n"; slowLog << "# Execute_time: " << execTime << "\n"; + slowLog << "# LockWait_time: " << sess->getLockWaitTime() << "\n"; slowLog << "# Thread_id: " << getCurThreadId() << "\n"; slowLog << "# Session_id: " << sess->id() << "\n"; slowLog << "# Read_Pack_ts: " << sess->getCtx()->getReadPacketTs() << "\n"; diff --git a/src/tendisplus/server/session.cpp b/src/tendisplus/server/session.cpp index 3217d779..986cb114 100644 --- a/src/tendisplus/server/session.cpp +++ b/src/tendisplus/server/session.cpp @@ -32,6 +32,7 @@ Session::Session(ServerEntry* svr, Type type) _ctx(std::make_unique(this)), _type(type), _timestamp(msSinceEpoch()), + _lockWaitTime(0), _sessId(_idGen.fetch_add(1, std::memory_order_relaxed)), _inLua(false) { _aliveCnt.fetch_add(1, std::memory_order_relaxed); diff --git a/src/tendisplus/server/session.h b/src/tendisplus/server/session.h index ecc1c9b3..fba5fc01 100644 --- a/src/tendisplus/server/session.h +++ b/src/tendisplus/server/session.h @@ -86,12 +86,29 @@ class Session : public std::enable_shared_from_this { return {}; } + uint64_t getLockWaitTime() const { + return _lockWaitTime; + } + + void setLockWaitTime(uint64_t time) { + _lockWaitTime = time; + } + + void addLockWaitTime(uint64_t time) { + _lockWaitTime += time; + } + + void resetLockWaitTime() { + _lockWaitTime = 0; + } + protected: std::vector _args; ServerEntry* _server; std::unique_ptr _ctx; Type _type; uint64_t _timestamp; + uint64_t _lockWaitTime; private: mutable std::mutex _baseMutex;