From 15a8a26b907ba5f2aa4a8bd632d659e4a0d384f2 Mon Sep 17 00:00:00 2001
From: Eric Cano <Eric.Cano@cern.ch>
Date: Thu, 17 May 2018 14:45:37 +0200
Subject: [PATCH] Added performance logging for agent ownership changes.
---
objectstore/Agent.cpp | 6 ++++++
objectstore/Agent.hpp | 2 ++
objectstore/AgentReference.cpp | 19 +++++++++++++++++++
3 files changed, 27 insertions(+)
diff --git a/objectstore/Agent.cpp b/objectstore/Agent.cpp
index 8653aab3de..7ef0bb2846 100644
--- a/objectstore/Agent.cpp
+++ b/objectstore/Agent.cpp
@@ -181,6 +181,12 @@ std::list<std::string>
return ret;
}
+size_t cta::objectstore::Agent::getOwnershipListSize() {
+ checkPayloadReadable();
+ return m_payload.ownedobjects_size();
+}
+
+
void cta::objectstore::Agent::bumpHeartbeat() {
checkPayloadWritable();
auto heartbeat=m_payload.heartbeat()+1;
diff --git a/objectstore/Agent.hpp b/objectstore/Agent.hpp
index 61ddcd080d..cd781ece32 100644
--- a/objectstore/Agent.hpp
+++ b/objectstore/Agent.hpp
@@ -117,6 +117,8 @@ private:
public:
std::list<std::string> getOwnershipList();
+ size_t getOwnershipListSize();
+
std::string dump();
void bumpHeartbeat();
diff --git a/objectstore/AgentReference.cpp b/objectstore/AgentReference.cpp
index aef93441bb..987850f01b 100644
--- a/objectstore/AgentReference.cpp
+++ b/objectstore/AgentReference.cpp
@@ -177,8 +177,13 @@ void AgentReference::queueAndExecuteAction(std::shared_ptr<Action> action, objec
log::LogContext lc(m_logger);
log::ScopedParamContainer params(lc);
params.add("agentObject", m_agentAddress);
+ utils::Timer t;
objectstore::ScopedExclusiveLock agl(ag);
+ double agentLockTime = t.secs(utils::Timer::resetCounter);
ag.fetch();
+ double agentFetchTime = t.secs(utils::Timer::resetCounter);
+ size_t agentOwnershipSizeBefore = ag.getOwnershipListSize();
+ size_t operationsCount = q->queue.size() + 1;
// First we apply our own modification
appyAction(*action, ag, lc);
// Then those of other threads
@@ -186,8 +191,22 @@ void AgentReference::queueAndExecuteAction(std::shared_ptr<Action> action, objec
threading::MutexLocker ml(a->mutex);
appyAction(*a, ag, lc);
}
+ size_t agentOwnershipSizeAfter = ag.getOwnershipListSize();
+ double agentUpdateTime = t.secs(utils::Timer::resetCounter);
// and commit
ag.commit();
+ double agentCommitTime = t.secs(utils::Timer::resetCounter);
+ {
+ log::ScopedParamContainer params(lc);
+ params.add("agentOwnershipSizeBefore", agentOwnershipSizeBefore)
+ .add("agentOwnershipSizeAfter", agentOwnershipSizeAfter)
+ .add("operationsCount", operationsCount)
+ .add("agentLockTime", agentLockTime)
+ .add("agentFetchTime", agentFetchTime)
+ .add("agentUpdateTime", agentUpdateTime)
+ .add("agentCommitTime", agentCommitTime);
+ lc.log(log::INFO, "In AgentReference::queueAndExecuteAction(): executed a batch of actions.");
+ }
// We avoid global log (with a count) as we would get one for each heartbeat.
} catch (...) {
// Something wend wrong: , we release the next batch of changes
--
GitLab