From cf0974181bd5e422a57a59f24c02f72b92b4ca4b Mon Sep 17 00:00:00 2001
From: haozturk <h.ozturk@cern.ch>
Date: Mon, 8 Jul 2019 19:57:05 +0200
Subject: [PATCH] Added a python script for plotting, plus did some code
clean-up
---
.../PerfMonComps/PerfMonComps/PerfMonMTSvc.h | 13 +-
.../PerfMonComps/PerfMonMTUtils.h | 73 +++------
.../python/PerfMonMTSvc_plotter.py | 82 ++++++++++
.../PerfMonComps/src/PerfMonMTSvc.cxx | 154 +++++++-----------
.../src/components/PerfMonComps_entries.cxx | 4 +-
5 files changed, 173 insertions(+), 153 deletions(-)
create mode 100644 Control/PerformanceMonitoring/PerfMonComps/python/PerfMonMTSvc_plotter.py
diff --git a/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTSvc.h b/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTSvc.h
index dfb62de65956..6b3b764c11ee 100644
--- a/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTSvc.h
+++ b/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTSvc.h
@@ -2,6 +2,10 @@
Copyright (C) 2002-2019 CERN for the benefit of the ATLAS collaboration
*/
+/*
+ * @authors: Alaettin Serhan Mete, Hasan Ozturk - alaettin.serhan.mete@cern.ch, haozturk@cern.ch
+ */
+
#ifndef PERFMONCOMPS_PERFMONMTSVC_H
#define PERFMONCOMPS_PERFMONMTSVC_H
@@ -65,21 +69,20 @@ class PerfMonMTSvc : virtual public IPerfMonMTSvc,
void report2Stdout();
void report2JsonFile();
- // Get the IncidentSvc
- //virtual void handle ( const Incident& incident ) override;
private:
/// Measurement to capture the CPU time
PMonMT::Measurement m_measurement;
- /// Data to hold the measurement
- /// We use pointer to the MeasurementData, because we use new keyword while creating them. Clear!
- //std::unordered_map < PMonMT::StepCompPair , PMonMT::MeasurementData* > m_compLevelDataMap;
+ /* Data structure to store component level measurements
+ * We use pointer to the MeasurementData, because we use new keyword while creating them. Clear!
+ */
std::map < PMonMT::StepCompPair , PMonMT::MeasurementData* > m_compLevelDataMap;
// Clear!
PMonMT::MeasurementData m_data[3];
+ //PMonMT::MeasurementData m_data[PMonMT::SnapshotStep];
}; // class PerfMonMTSvc
diff --git a/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTUtils.h b/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTUtils.h
index 8a71ace2b09e..e2aa60a8845a 100644
--- a/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTUtils.h
+++ b/Control/PerformanceMonitoring/PerfMonComps/PerfMonComps/PerfMonMTUtils.h
@@ -2,6 +2,11 @@
Copyright (C) 2002-2019 CERN for the benefit of the ATLAS collaboration
*/
+/*
+ * @authors: Alaettin Serhan Mete, Hasan Ozturk - alaettin.serhan.mete@cern.ch, haozturk@cern.ch
+ */
+
+
#ifndef PERFMONCOMPS_PERFMONMTUTILS_H
#define PERFMONCOMPS_PERFMONMTUTILS_H
@@ -24,10 +29,6 @@ namespace PMonMT {
double get_process_cpu_time();
double get_wall_time();
- //IMessageSvc *msgSvc;
- //MsgStream msg( msgSvc, "PerfMonMTUtils" );
-
-
// Basic Measurement
struct Measurement {
double cpu_time;
@@ -36,11 +37,12 @@ namespace PMonMT {
cpu_time = get_process_cpu_time();
wall_time = get_wall_time();
+ /* Log to stdout
IMessageSvc *msgSvc;
MsgStream msg( msgSvc, "PerfMonMTUtils" );
-
- //msg << MSG::INFO << std::fixed << "Capture: CPU: " << cpu_time << ", Wall: " << wall_time << endmsg;
- //ATH_MSG_INFO("Capture: CPU: " << cpu_time << ", Wall: " << wall_time);
+ msg << MSG::INFO << std::fixed << "Capture: CPU: " << cpu_time << ", Wall: " << wall_time << endmsg;
+ ATH_MSG_INFO("Capture: CPU: " << cpu_time << ", Wall: " << wall_time);
+ */
}
Measurement() : cpu_time{0.}, wall_time{0.} { }
};
@@ -53,20 +55,23 @@ namespace PMonMT {
void addPointStart(const Measurement& meas) {
m_tmp_cpu = meas.cpu_time;
m_tmp_wall = meas.wall_time;
-
+
+ /* Log to stdout
IMessageSvc *msgSvc;
MsgStream msg( msgSvc, "PerfMonMTUtils" );
-
- //msg << MSG::INFO << "addPointStart: CPU: " << m_tmp_cpu << ", Wall: " << m_tmp_wall << endmsg;
+ msg << MSG::INFO << "addPointStart: CPU: " << m_tmp_cpu << ", Wall: " << m_tmp_wall << endmsg;
+ */
}
void addPointStop(const Measurement& meas) {
m_delta_cpu = meas.cpu_time - m_tmp_cpu;
m_delta_wall = meas.wall_time - m_tmp_wall;
+ /* Log to stdout
IMessageSvc *msgSvc;
MsgStream msg( msgSvc, "PerfMonMTUtils" );
- //msg << MSG::INFO << "addPointStop: delta_CPU: " << meas.cpu_time << " - " << m_tmp_cpu << " = " << m_delta_cpu << endmsg;
- //msg << MSG::INFO << "addPointStop: delta_Wall: " << meas.wall_time << " - " << m_tmp_wall << " = " << m_delta_wall << endmsg;
+ msg << MSG::INFO << "addPointStop: delta_CPU: " << meas.cpu_time << " - " << m_tmp_cpu << " = " << m_delta_cpu << endmsg;
+ msg << MSG::INFO << "addPointStop: delta_Wall: " << meas.wall_time << " - " << m_tmp_wall << " = " << m_delta_wall << endmsg;
+ */
}
MeasurementData() : m_tmp_cpu{0.}, m_delta_cpu{0.}, m_tmp_wall{0.}, m_delta_wall{0.} { }
};
@@ -77,52 +82,24 @@ namespace PMonMT {
std::string stepName;
std::string compName;
- // Overload std::less
+ // Overload < operator, because we are using a custom key(StepCompPair) for std::map
bool operator<(const StepCompPair& sc) const {
- //return (this->compName < t.compName);
- //return std::make_pair( this->compName, this->stepName ) < std::make_pair( sc.compName, sc.stepName );
- //return std::make_pair( sc.compName, sc.stepName ) < std::make_pair( this->compName, this->stepName ) ;
return std::make_pair( this->stepName, this->compName ) < std::make_pair( sc.stepName, sc.compName );
}
- /* Overload < operator for std::map, because we are using custom struct as a key
- bool operator < (const StepCompPair& A) const {
- return stepName < A.stepName;
- }*/
+ };
+
+ // Name of the step whose snapshot is taken by the service
+ struct SnapshotStep {
+
+ // Initialize - Event Loop - Finalize
+ std::string snapshotStep;
};
}
-/*
-namespace std {
-
- auto comp = [](const PMonMT::StepCompPair& c1, const PMonMT::StepCompPair& c2){
- return c1.stepName < c2.stepName || (c1.stepName == c2.stepName && c1.compName < c2.compName);
- };
-};*/
-
-
-
-/* For usage of undordered_map
-namespace std {
- template <> struct hash<PMonMT::StepCompPair> {
- size_t operator()(const PMonMT::StepCompPair & x) const {
- std::hash<std::string> h;
- return h(x.stepName) ^ h(x.compName);
- }
- };
-
- bool operator == (const PMonMT::StepCompPair &s1, const PMonMT::StepCompPair &s2)
- {
- if( s1.stepName == s2.stepName && s1.compName == s2.compName)
- return true;
- else
- return false;
- }
-}
-*/
///////////////////////////////////////////////////////////////////
// Inline methods:
///////////////////////////////////////////////////////////////////
diff --git a/Control/PerformanceMonitoring/PerfMonComps/python/PerfMonMTSvc_plotter.py b/Control/PerformanceMonitoring/PerfMonComps/python/PerfMonMTSvc_plotter.py
new file mode 100644
index 000000000000..181881960114
--- /dev/null
+++ b/Control/PerformanceMonitoring/PerfMonComps/python/PerfMonMTSvc_plotter.py
@@ -0,0 +1,82 @@
+# Copyright (C) 2002-2019 CERN for the benefit of the ATLAS collaboration
+
+# @author: Hasan Ozturk <haozturk@cern.ch>
+
+
+__author__ = "Hasan Ozturk <haozturk@cern.ch"
+__doc__ = "A python module which parses the PerfMonMTSvc results and makes plots"
+
+
+import sys
+import json
+
+import matplotlib
+matplotlib.use('PDF') # use PDF backend
+import matplotlib.pyplot as plt
+import numpy as np
+
+if ( len(sys.argv) != 2 ):
+ print("Please give result file as an argument!")
+
+# Get the result Json file
+result_file = sys.argv[1]
+
+with open( result_file ) as json_file:
+ data = json.load(json_file)
+
+ #fig = plt.figure(figsize=(15,75)) # for HelloWorld
+ fig = plt.figure(figsize=(31,150)) # for Sisp
+
+ stepNum = len(data)
+
+ for i, step in enumerate(data):
+ components = []
+ cpu_times = []
+ wall_times = []
+
+ for component in data[step]:
+
+ cpu_time = data[step][component]['cpu_time']
+ wall_time = data[step][component]['wall_time']
+
+ # Only take nonzero components
+ if cpu_time != 0 or wall_time != 0:
+ components.append(component)
+ cpu_times.append(cpu_time) # Clear!
+ wall_times.append(wall_time)
+
+ # if there is no nonzero in the step, then skip it
+ if len(components) == 0:
+ continue
+
+ # Horizontal Bar Chart
+ ax = fig.add_subplot(stepNum,1,i+1)
+
+ index = np.arange(len(components))
+ bar_width = 0.35
+ opacity = 0.8
+
+ rects1 = plt.barh(index + (1.5)*bar_width, cpu_times,bar_width,
+ alpha=opacity,
+ color='b',
+ label='CPU Time')
+
+ rects2 = plt.barh(index + bar_width/2, wall_times, bar_width,
+ alpha=opacity,
+ color='g',
+ label='Wall Time')
+
+ plt.ylabel('Components',fontsize = 35)
+ plt.xlabel('Time(ms)', fontsize = 35)
+ plt.title(step, fontsize = 40, fontweight = "bold")
+ plt.yticks(index + bar_width, components)
+ plt.legend()
+
+ ax.tick_params(axis='both', which='major', labelsize=30)
+ ax.tick_params(axis='both', which='minor', labelsize=30)
+
+
+ fig.set_tight_layout( True )
+
+
+ fig.savefig("PerfMonMTSvc_plot.pdf")
diff --git a/Control/PerformanceMonitoring/PerfMonComps/src/PerfMonMTSvc.cxx b/Control/PerformanceMonitoring/PerfMonComps/src/PerfMonMTSvc.cxx
index f07d128f937c..2e4c9d375072 100644
--- a/Control/PerformanceMonitoring/PerfMonComps/src/PerfMonMTSvc.cxx
+++ b/Control/PerformanceMonitoring/PerfMonComps/src/PerfMonMTSvc.cxx
@@ -2,6 +2,10 @@
Copyright (C) 2002-2019 CERN for the benefit of the ATLAS collaboration
*/
+/*
+ * @authors: Alaettin Serhan Mete, Hasan Ozturk - alaettin.serhan.mete@cern.ch, haozturk@cern.ch
+ */
+
// Framework includes
#include "GaudiKernel/ThreadLocalContext.h"
@@ -9,8 +13,8 @@
#include "PerfMonComps/PerfMonMTSvc.h"
#include "PerfMonUtils.h" // borrow from existing code
+// Input/Output includes
#include <fstream>
-
#include <nlohmann/json.hpp>
using json = nlohmann::json; // for convenience
@@ -22,7 +26,7 @@ PerfMonMTSvc::PerfMonMTSvc( const std::string& name,
ISvcLocator* pSvcLocator )
: AthService( name, pSvcLocator ) {
- ATH_MSG_INFO(" Pre initialization is captured! ");
+ //ATH_MSG_INFO(" Pre initialization is captured! ");
m_measurement.capture();
m_data[0].addPointStart(m_measurement);
@@ -30,8 +34,6 @@ PerfMonMTSvc::PerfMonMTSvc( const std::string& name,
PerfMonMTSvc::~PerfMonMTSvc(){
- ATH_MSG_INFO("Destructor!!!");
-
}
/*
@@ -57,26 +59,11 @@ StatusCode PerfMonMTSvc::queryInterface( const InterfaceID& riid,
StatusCode PerfMonMTSvc::initialize() {
ATH_MSG_INFO("Initialize");
- // Trying to start our service as soon as possible
- startAud ( "Initialize", "PerfMonMTSlice" );
-
/// Configure the auditor
if( !PerfMon::makeAuditor("PerfMonMTAuditor", auditorSvc(), msg()).isSuccess()) {
ATH_MSG_ERROR("Could not register auditor [PerfMonMTAuditor]!");
return StatusCode::FAILURE;
}
- /*
- // Get the IncidentSvc to capture the the moment when all components halt
- ServiceHandle < IIncidentSvc > incSvc( "IncidentSvc", this->name() );
- if( !incSvc.retrieve().isSuccess() ){
-
- ATH_MSG_ERROR("Could not retrieve the IncidentSvc!");
- return StatusCode::FAILURE;
-
- }
-
- incSvc->addListener( this, IncidentType::SvcPostFinalize );
- */
return StatusCode::SUCCESS;
}
@@ -84,8 +71,9 @@ StatusCode PerfMonMTSvc::initialize() {
* Finalize the Service
*/
StatusCode PerfMonMTSvc::finalize(){
- ATH_MSG_INFO("Finalize");
- ATH_MSG_INFO("Post Finalization is captured!");
+
+ //ATH_MSG_INFO("Finalize");
+ //ATH_MSG_INFO("Post Finalization is captured!");
m_measurement.capture();
m_data[2].addPointStop(m_measurement);
@@ -98,9 +86,15 @@ StatusCode PerfMonMTSvc::finalize(){
*/
void PerfMonMTSvc::startAud( const std::string& stepName,
const std::string& compName ) {
+ /*
+ * This if statement is temporary. It will be removed.
+ * In current implementation the very first thing called is stopAud function
+ * for PerfMonMTSvc. There are some components before it. We miss them.
+ * It should be fixed.
+ */
if( compName != "PerfMonMTSvc" ){
- startSnapshotAud(stepName, compName);
- startCompLevelAud(stepName, compName);
+ startSnapshotAud(stepName, compName);
+ startCompLevelAud(stepName, compName);
}
}
@@ -110,16 +104,15 @@ void PerfMonMTSvc::startAud( const std::string& stepName,
void PerfMonMTSvc::stopAud( const std::string& stepName,
const std::string& compName ) {
if( compName != "PerfMonMTSvc" ){
- stopCompLevelAud(stepName, compName);
- stopSnapshotAud(stepName, compName);
+ stopCompLevelAud(stepName, compName);
+ stopSnapshotAud(stepName, compName);
}
}
void PerfMonMTSvc::startSnapshotAud( const std::string& stepName,
const std::string& compName ) {
- ATH_MSG_INFO("PerfMonMTSvc::startAud: stepName: " << stepName << ", compName: " << compName);
- m_measurement.capture(); // just to debug
+ //ATH_MSG_INFO("PerfMonMTSvc::startAud: stepName: " << stepName << ", compName: " << compName);
// Last thing to be called before the event loop begins
if( compName == "AthRegSeq" && stepName == "Start") {
@@ -135,20 +128,18 @@ void PerfMonMTSvc::startSnapshotAud( const std::string& stepName,
m_data[2].addPointStart(m_measurement);
}
- // Just to debug: Understand how much time we miss (AuditorSvc finalizes last)
+ /* Later we may need this
if ( compName == "AuditorSvc" && stepName == "Finalize"){
- //ATH_MSG_INFO("AUDITOR SERVICE IS CAPTURED!");
m_measurement.capture();
}
-
+ */
}
void PerfMonMTSvc::stopSnapshotAud( const std::string& stepName,
const std::string& compName ) {
- ATH_MSG_INFO("PerfMonMTSvc::stopAud: stepName: " << stepName << ", compName: " << compName);
- m_measurement.capture(); // just to debug
+ //ATH_MSG_INFO("PerfMonMTSvc::stopAud: stepName: " << stepName << ", compName: " << compName);
// First thing to be called after the initialize step ends
if ( compName == "AthMasterSeq" && stepName == "Initialize"){
@@ -165,27 +156,23 @@ void PerfMonMTSvc::stopSnapshotAud( const std::string& stepName,
m_data[1].addPointStop(m_measurement);
}
- // Just to debug: How much time passes in PerfMonMTSvc configuration
- if ( compName == "PerfMonMTSvc" && stepName == "Initialize"){
- //ATH_MSG_INFO("PerfMonMTSvc IS CAPTURED!");
- m_measurement.capture();
- }
-
}
void PerfMonMTSvc::startCompLevelAud( const std::string& stepName,
const std::string& compName) {
-
+
+ // Current step - component pair. Ex: Initialize-StoreGateSvc
PMonMT::StepCompPair currentState;
currentState.stepName = stepName;
currentState.compName = compName;
- m_measurement.capture();
+ // Capture the time
+ m_measurement.capture();
/*
* Dynamically create a MeasurementData instance for the current step-component pair
- * Do not forget to delete the dynamically allocated space!
+ * This space will be freed after results are reported.
*/
m_compLevelDataMap[currentState] = new PMonMT::MeasurementData;
m_compLevelDataMap[currentState]->addPointStart(m_measurement);
@@ -194,9 +181,11 @@ void PerfMonMTSvc::startCompLevelAud( const std::string& stepName,
void PerfMonMTSvc::stopCompLevelAud( const std::string& stepName,
const std::string& compName) {
-
+
+ // Capture the time
m_measurement.capture();
+ // Current step - component pair. Ex: Initialize-StoreGateSvc
PMonMT::StepCompPair currentState;
currentState.stepName = stepName;
currentState.compName = compName;
@@ -208,64 +197,34 @@ void PerfMonMTSvc::stopCompLevelAud( const std::string& stepName,
}
-/*
-void PerfMonMTSvc::handle( const Incident& incident ){
-
- // When all finalize steps of all components end, create report
- if(incident.type() == IncidentType::SvcPostFinalize ){
- ATH_MSG_INFO("POST FINALIZATION IS CAPTURED!");
- m_measurement.capture();
- m_data[2].addPointStop(m_measurement);
- report();
- }
-
-}
-*/
// Report the results
void PerfMonMTSvc::report(){
report2Stdout();
report2JsonFile();
- /*
- ATH_MSG_INFO("=========================================================");
- ATH_MSG_INFO(" PerfMonMT Results Summary ");
- ATH_MSG_INFO("=========================================================");
-
- ATH_MSG_INFO("Total Wall time in the Initialization is " << m_data[0].m_delta_wall << " ms ");
- ATH_MSG_INFO("Total CPU time in the Initialization is " << m_data[0].m_delta_cpu << " ms ");
- ATH_MSG_INFO("Average CPU utilization in the Initialization is " <<
- m_data[0].m_delta_cpu/m_data[0].m_delta_wall );
- ATH_MSG_INFO("");
-
- ATH_MSG_INFO("Total Wall time in the event loop is " << m_data[1].m_delta_wall << " ms ");
- ATH_MSG_INFO("Total CPU time in the event loop is " << m_data[1].m_delta_cpu << " ms ");
- ATH_MSG_INFO("Average CPU utilization in the event loop is " <<
- m_data[1].m_delta_cpu/m_data[1].m_delta_wall );
- ATH_MSG_INFO("");
-
- ATH_MSG_INFO("Total Wall time in the Finalize is " << m_data[2].m_delta_wall << " ms ");
- ATH_MSG_INFO("Total CPU time in the Finalize is " << m_data[2].m_delta_cpu << " ms ");
- ATH_MSG_INFO("Average CPU utilization in the Finalize is " <<
- m_data[2].m_delta_cpu/m_data[2].m_delta_wall );
- ATH_MSG_INFO("");
-
- ATH_MSG_INFO("=========================================================");
-
- ATH_MSG_INFO("=========================================================");
- ATH_MSG_INFO(" Component Level Monitoring ");
- ATH_MSG_INFO("=========================================================");
-
- // Clear! ->
- ATH_MSG_INFO( "Step CPU Wall Component" );
- for(auto& it : m_compLevelDataMap)
- ATH_MSG_INFO( it.first.stepName << ": " << it.second->m_delta_cpu << " - " << it.second->m_delta_wall << " " << it.first.compName );
-
- for(auto& it : m_compLevelDataMap)
- delete it.second;
- */
}
+/*
+ * JSON Format:
+ *
+ * {
+ * "Initialize" : {
+ * "comp1" : {
+ * "cpu_time" : cpu_measurement
+ * "wall_time": wall_measurement
+ * },
+ * "comp2": ...
+ * },
+ *
+ * "Start": {...},
+ * "Stop" : {...},
+ * "Finalize": {...}
+ * }
+ *
+ * Output Filename: PerfMonMTSvc_result.json
+ */
+
void PerfMonMTSvc::report2JsonFile(){
json j;
@@ -282,12 +241,12 @@ void PerfMonMTSvc::report2JsonFile(){
}
- std::ofstream o("pretty.json");
+ std::ofstream o("PerfMonMTSvc_result.json");
o << std::setw(4) << j << std::endl;
}
-void PerfMonMTSvc::report2Stdout(){
+void PerfMonMTSvc::report2Stdout(){
ATH_MSG_INFO("=========================================================");
ATH_MSG_INFO(" PerfMonMT Results Summary ");
@@ -309,7 +268,7 @@ void PerfMonMTSvc::report2Stdout(){
ATH_MSG_INFO("Total CPU time in the Finalize is " << m_data[2].m_delta_cpu << " ms ");
ATH_MSG_INFO("Average CPU utilization in the Finalize is " <<
m_data[2].m_delta_cpu/m_data[2].m_delta_wall );
- ATH_MSG_INFO("");
+
ATH_MSG_INFO("=========================================================");
@@ -319,11 +278,10 @@ void PerfMonMTSvc::report2Stdout(){
// Clear! ->
ATH_MSG_INFO( "Step CPU Wall Component" );
- for(auto& it : m_compLevelDataMap)
+ for(auto& it : m_compLevelDataMap){
ATH_MSG_INFO( it.first.stepName << ": " << it.second->m_delta_cpu << " - " << it.second->m_delta_wall << " " << it.first.compName );
-
- for(auto& it : m_compLevelDataMap)
delete it.second;
+ }
}
diff --git a/Control/PerformanceMonitoring/PerfMonComps/src/components/PerfMonComps_entries.cxx b/Control/PerformanceMonitoring/PerfMonComps/src/components/PerfMonComps_entries.cxx
index 60e2aebfc768..122960cffb56 100644
--- a/Control/PerformanceMonitoring/PerfMonComps/src/components/PerfMonComps_entries.cxx
+++ b/Control/PerformanceMonitoring/PerfMonComps/src/components/PerfMonComps_entries.cxx
@@ -6,7 +6,7 @@
#include "../PerfMonStorePayloadMon.h"
#include "PerfMonComps/PerfMonMTSvc.h"
-#include "PerfMonComps/PerfMonMTAlg.h"
+//#include "PerfMonComps/PerfMonMTAlg.h"
#include "PerfMonComps/PerfMonMTAuditor.h"
DECLARE_COMPONENT( PerfMonSvc )
@@ -18,5 +18,5 @@ DECLARE_COMPONENT( PerfMon::CallGraphAuditor )
DECLARE_COMPONENT( PerfMon::StorePayloadMon )
DECLARE_COMPONENT( PerfMonMTSvc )
-DECLARE_COMPONENT( PerfMonMTAlg )
+//DECLARE_COMPONENT( PerfMonMTAlg )
DECLARE_COMPONENT( PerfMonMTAuditor )
--
GitLab