Logo ROOT  
Reference Guide
 
Loading...
Searching...
No Matches
ProcessTimer.cxx
Go to the documentation of this file.
1/*
2 * Project: RooFit
3 * Authors:
4 * ZW, Zef Wolffs, Nikhef, zefwolffs@gmail.com
5 * PB, Patrick Bos, Netherlands eScience Center, p.bos@esciencecenter.nl
6 *
7 * Copyright (c) 2022, CERN
8 *
9 * Redistribution and use in source and binary forms,
10 * with or without modification, are permitted according to the terms
11 * listed in LICENSE (http://roofit.sourceforge.net/license.txt)
12 */
13
15
16#include <iostream>
17#include <fstream>
18#include <iomanip> // setw
19
20using std::list, std::string, std::invalid_argument, std::cout, std::endl, std::to_string, std::ios;
21namespace chrono = std::chrono; // alias
22
23namespace RooFit {
24namespace MultiProcess {
25
26/** \class ProcessTimer
27 *
28 * \brief Can be used to generate timings of multiple processes simultaneously and output logs
29 *
30 * This static class records timings of multiple processes simultaneously and allows for these
31 * timings to be written out in json format, one file for each process. Multiple overlapping
32 * sections can be timed independently on the same process. It also allows for the timings
33 * to be written out to json logfiles in a specified interval, for example every half hour.
34 *
35 * Note that this class logs timings in milliseconds.
36 */
37
38list<chrono::time_point<chrono::steady_clock>> ProcessTimer::get_durations(string to_return)
39{
40 ProcessTimer::duration_map_t::key_type sec_name;
41 ProcessTimer::duration_map_t::mapped_type duration_list;
42 for (auto const &durations_element : ProcessTimer::durations) {
43 std::tie(sec_name, duration_list) = durations_element;
44 if (sec_name != to_return) {
45 continue;
46 } else {
47 return duration_list;
48 }
49 }
50 throw ::invalid_argument("section name " + to_return +
51 " not found in timer map, so it cannot"
52 " be retrieved");
53}
54
55void ProcessTimer::start_timer(string section_name)
56{
57 auto it = ProcessTimer::durations.find(section_name);
58 if (it == ProcessTimer::durations.end()) {
59 // Key does not exist in map yet, start the first timer of this section
60 ProcessTimer::durations.insert({section_name, {chrono::steady_clock::now()}});
61 } else if (it->second.size() % 2 != 0) {
62 // All even indices contain start times, if size of list is currently even we can not start a new timer
63 throw ::invalid_argument("Section name " + section_name +
64 " timer has already started, and was not stopped before calling `start_timer`");
65 } else {
66 // Add start time to list
67 it->second.push_back(chrono::steady_clock::now());
68 }
69}
70
71void ProcessTimer::end_timer(string section_name)
72{
73 auto it = ProcessTimer::durations.find(section_name);
74 if (it == ProcessTimer::durations.end()) {
75 // Key does not exist in map yet
76 throw ::invalid_argument("Section name " + section_name + " timer was never started!");
77 } else if (it->second.size() % 2 == 0) {
78 // All odd indices contain end times, if size of list is currently odd we can not start a new timer
79 throw ::invalid_argument("Section name " + section_name +
80 " timer does exist, but was not started before calling `end_timer`");
81 } else {
82 // Add end time to list
83 it->second.push_back(chrono::steady_clock::now());
84 }
85
86 // Write to file intermittently if interval is reached and write_interval is set
87 if (write_interval && (chrono::duration_cast<chrono::seconds>(chrono::steady_clock::now() - previous_write).count() >
89 previous_write = chrono::steady_clock::now();
92 }
93}
94
95void ProcessTimer::print_durations(string to_print)
96{
97 cout << "On PID: " << ProcessTimer::process << endl << "====================" << endl << endl;
98 ProcessTimer::duration_map_t::key_type sec_name;
99 ProcessTimer::duration_map_t::mapped_type duration_list;
100 for (auto const &durations_element : ProcessTimer::durations) {
101 std::tie(sec_name, duration_list) = durations_element;
102 if (to_print != "all" && sec_name != to_print)
103 continue; // continue if only asked for specific section
104
105 int i = 0;
106 long total_duration = 0;
107 cout << "Section name " << sec_name << ":" << endl;
108 for (auto it = duration_list.begin(); it != duration_list.end(); ++it) {
109 long duration = chrono::duration_cast<chrono::milliseconds>(*std::next(it) - *it).count();
110 cout << "Duration " << i << ": " << duration << "ms +" << endl;
111 total_duration += duration;
112 i++;
113 }
114 cout << "--------------------" << endl << "Total: " << total_duration << "ms" << endl << endl;
115 }
116}
117
119{
120 cout << "On PID: " << ProcessTimer::process << endl;
121 ProcessTimer::duration_map_t::key_type sec_name;
122 ProcessTimer::duration_map_t::mapped_type duration_list;
123 for (auto const &durations_element : ProcessTimer::durations) {
124 std::tie(sec_name, duration_list) = durations_element;
125 int i = 0;
126 cout << "Section name " << sec_name << ":" << endl;
127 for (auto it = duration_list.begin(); it != duration_list.end(); ++it) {
128 long duration_since_begin_start =
129 chrono::duration_cast<chrono::milliseconds>(*it - ProcessTimer::begin).count();
130
131 long duration_since_begin_end =
132 chrono::duration_cast<chrono::milliseconds>(*std::next(it) - ProcessTimer::begin).count();
133
134 cout << "Duration " << i << ": " << duration_since_begin_start << "ms-->" << duration_since_begin_end << "ms"
135 << endl;
136 i++;
137 }
138 }
139}
140
142{
143 json j;
144 j["metadata"] = metadata;
145 std::ofstream file("p_" + to_string((long)ProcessTimer::get_process()) + ".json." + to_string(times_written),
146 ios::app);
147 list<long> durations_since_begin;
148
149 ProcessTimer::duration_map_t::key_type sec_name;
150 ProcessTimer::duration_map_t::mapped_type duration_list;
151 for (auto const &durations_element : ProcessTimer::durations) {
152 std::tie(sec_name, duration_list) = durations_element;
153 durations_since_begin.clear();
154 for (auto const &timestamp : duration_list) {
155 durations_since_begin.push_back(
156 chrono::duration_cast<chrono::microseconds>(timestamp - ProcessTimer::begin).count());
157 }
158 j[sec_name] = durations_since_begin;
159 }
160 file << std::setw(4) << j;
161 file.close();
162}
163
165{
166 if (write_interval) {
167 json j;
168 json meta;
169 meta.push_back(std::move(data));
170 j["metadata"] = meta;
171 std::ofstream file("p_" + to_string((long)ProcessTimer::get_process()) + ".json", ios::app);
172 file << std::setw(4) << j;
173 } else {
174 metadata.push_back(std::move(data));
175 }
176}
177
179{
180 write_interval = write_int;
181 if (write_interval) {
182 json j;
183 json meta;
184 meta["write_interval"] = true;
185 j["metadata"] = meta;
186 std::ofstream file("p_" + to_string((long)ProcessTimer::get_process()) + ".json", ios::app);
187 file << std::setw(4) << j;
188 }
189}
190
191// Initialize static members
193chrono::time_point<chrono::steady_clock> ProcessTimer::begin = chrono::steady_clock::now();
194chrono::time_point<chrono::steady_clock> ProcessTimer::previous_write = chrono::steady_clock::now();
195pid_t ProcessTimer::process = 0;
199
200} // namespace MultiProcess
201} // namespace RooFit
nlohmann::json json
Option_t Option_t TPoint TPoint const char GetTextMagnitude GetFillStyle GetLineColor GetLineWidth GetMarkerStyle GetTextAlign GetTextColor GetTextSize void data
static void add_metadata(json data)
static void set_write_interval(int write_interval)
static void print_durations(std::string to_print="all")
static std::chrono::time_point< std::chrono::steady_clock > begin
static std::list< std::chrono::time_point< std::chrono::steady_clock > > get_durations(std::string section_name)
static std::chrono::time_point< std::chrono::steady_clock > previous_write
static void start_timer(std::string section_name)
std::map< std::string, std::list< std::chrono::time_point< std::chrono::steady_clock > > > duration_map_t
static duration_map_t durations
static void end_timer(std::string section_name)
The namespace RooFit contains mostly switches that change the behaviour of functions of PDFs (or othe...
Definition JSONIO.h:26