1 /*
2 * Copyright (c) 2019 Simon Frasch
3 *
4 * Redistribution and use in source and binary forms, with or without
5 * modification, are permitted provided that the following conditions are met:
6 *
7 * 1. Redistributions of source code must retain the above copyright notice,
8 * this list of conditions and the following disclaimer.
9 * 2. Redistributions in binary form must reproduce the above copyright
10 * notice, this list of conditions and the following disclaimer in the
11 * documentation and/or other materials provided with the distribution.
12 * 3. Neither the name of the copyright holder nor the names of its contributors
13 * may be used to endorse or promote products derived from this software
14 * without specific prior written permission.
15 *
16 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
17 * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19 * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
20 * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
21 * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
22 * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
23 * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
24 * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
25 * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
26 * POSSIBILITY OF SUCH DAMAGE.
27 */
28
29 #include "rt_graph.hpp"
30 #include <algorithm>
31 #include <cmath>
32 #include <iomanip>
33 #include <numeric>
34 #include <ostream>
35 #include <ratio>
36 #include <sstream>
37 #include <string>
38 #include <tuple>
39
40 namespace rt_graph {
41
42 // ======================
43 // internal helper
44 // ======================
45 namespace internal {
46 namespace {
47
48 struct Format {
Formatrt_graph::internal::__anonb6efb27b0111::Format49 Format(Stat stat_) : stat(stat_) {
50 switch (stat_) {
51 case Stat::Count:
52 header = "#";
53 space = 6;
54 break;
55 case Stat::Total:
56 header = "Total";
57 space = 14;
58 break;
59 case Stat::Mean:
60 header = "Mean";
61 space = 14;
62 break;
63 case Stat::Median:
64 header = "Median";
65 space = 14;
66 break;
67 case Stat::QuartileHigh:
68 header = "Quartile High";
69 space = 14;
70 break;
71 case Stat::QuartileLow:
72 header = "Quartile Low";
73 space = 14;
74 break;
75 case Stat::Min:
76 header = "Min";
77 space = 14;
78 break;
79 case Stat::Max:
80 header = "Max";
81 space = 14;
82 break;
83 case Stat::Percentage:
84 header = "%";
85 space = 11;
86 break;
87 case Stat::ParentPercentage:
88 header = "Parent %";
89 space = 11;
90 break;
91 }
92 }
93
94 Stat stat;
95 std::string header;
96 std::size_t space;
97 };
98
99 // format time input in seconds into string with appropriate unit
format_time(const double time_seconds)100 auto format_time(const double time_seconds) -> std::string {
101 if (time_seconds <= 0.0) return std::string("0 s");
102
103 // time is always greater than 0 here
104 const double exponent = std::log10(std::abs(time_seconds));
105 const int siExponent = static_cast<int>(std::floor(exponent / 3.0) * 3);
106
107 std::stringstream result;
108 result << std::fixed << std::setprecision(2);
109 result << time_seconds * std::pow(10.0, static_cast<double>(-siExponent));
110 result << " ";
111 switch (siExponent) {
112 case 24:
113 result << "Y";
114 break;
115 case 21:
116 result << "Z";
117 break;
118 case 18:
119 result << "E";
120 break;
121 case 15:
122 result << "P";
123 break;
124 case 12:
125 result << "T";
126 break;
127 case 9:
128 result << "G";
129 break;
130 case 6:
131 result << "M";
132 break;
133 case 3:
134 result << "k";
135 break;
136 case 0:
137 break;
138 case -3:
139 result << "m";
140 break;
141 case -6:
142 result << "u";
143 break;
144 case -9:
145 result << "n";
146 break;
147 case -12:
148 result << "p";
149 break;
150 case -15:
151 result << "f";
152 break;
153 case -18:
154 result << "a";
155 break;
156 case -21:
157 result << "z";
158 break;
159 case -24:
160 result << "y";
161 break;
162 default:
163 result << "?";
164 }
165 result << "s";
166 return result.str();
167 }
168
calc_median(const std::vector<double>::const_iterator & begin,const std::vector<double>::const_iterator & end)169 auto calc_median(const std::vector<double>::const_iterator& begin,
170 const std::vector<double>::const_iterator& end) -> double {
171 const auto n = end - begin;
172 if (n == 0) return 0.0;
173 if (n % 2 == 0) {
174 return (*(begin + n / 2) + *(begin + n / 2 - 1)) / 2.0;
175 } else {
176 return *(begin + n / 2);
177 }
178 }
179
print_stat(std::ostream & out,const Format & format,const std::vector<double> & sortedTimings,double totalSum,double parentSum,double currentSum)180 auto print_stat(std::ostream& out, const Format& format, const std::vector<double>& sortedTimings,
181 double totalSum, double parentSum, double currentSum) -> void {
182 switch (format.stat) {
183 case Stat::Count:
184 out << std::right << std::setw(format.space) << sortedTimings.size();
185 break;
186 case Stat::Total:
187 out << std::right << std::setw(format.space) << format_time(currentSum);
188 break;
189 case Stat::Mean:
190 out << std::right << std::setw(format.space)
191 << format_time(currentSum / sortedTimings.size());
192 break;
193 case Stat::Median:
194 out << std::right << std::setw(format.space)
195 << format_time(calc_median(sortedTimings.begin(), sortedTimings.end()));
196 break;
197 case Stat::QuartileHigh: {
198 const double upperQuartile =
199 calc_median(sortedTimings.begin() + sortedTimings.size() / 2 +
200 (sortedTimings.size() % 2) * (sortedTimings.size() > 1),
201 sortedTimings.end());
202 out << std::right << std::setw(format.space) << format_time(upperQuartile);
203 } break;
204 case Stat::QuartileLow: {
205 const double lowerQuartile =
206 calc_median(sortedTimings.begin(), sortedTimings.begin() + sortedTimings.size() / 2);
207 out << std::right << std::setw(format.space) << format_time(lowerQuartile);
208 } break;
209 case Stat::Min:
210 out << std::right << std::setw(format.space) << format_time(sortedTimings.front());
211 break;
212 case Stat::Max:
213 out << std::right << std::setw(format.space) << format_time(sortedTimings.back());
214 break;
215 case Stat::Percentage: {
216 const double p =
217 (totalSum < currentSum || totalSum == 0) ? 100.0 : currentSum / totalSum * 100.0;
218 out << std::right << std::fixed << std::setprecision(2) << std::setw(format.space) << p;
219 } break;
220 case Stat::ParentPercentage: {
221 const double p =
222 (parentSum < currentSum || parentSum == 0) ? 100.0 : currentSum / parentSum * 100.0;
223 out << std::right << std::fixed << std::setprecision(2) << std::setw(format.space) << p;
224 } break;
225 }
226 }
227
228 // Helper struct for creating a tree of timings
229 struct TimeStampPair {
230 std::string identifier;
231 double time = 0.0;
232 std::size_t startIdx = 0;
233 std::size_t stopIdx = 0;
234 internal::TimingNode* nodePtr = nullptr;
235 };
236
calculate_statistic(std::vector<double> values)237 auto calculate_statistic(std::vector<double> values)
238 -> std::tuple<double, double, double, double, double, double, double> {
239 if (values.empty()) return std::make_tuple(0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0);
240 std::sort(values.begin(), values.end());
241
242 const double min = values.front();
243 const double max = values.back();
244
245 const double median = calc_median(values.begin(), values.end());
246 const double sum = std::accumulate(values.begin(), values.end(), 0.0);
247 const double mean = sum / values.size();
248
249 const double lowerQuartile = calc_median(values.begin(), values.begin() + values.size() / 2);
250 const double upperQuartile = calc_median(
251 values.begin() + values.size() / 2 + (values.size() % 2) * (values.size() > 1), values.end());
252
253 return std::make_tuple(sum, mean, median, min, max, lowerQuartile, upperQuartile);
254 }
255
256 // print rt_graph nodes in tree recursively
print_node(std::ostream & out,const std::vector<internal::Format> formats,const std::size_t identifierSpace,const std::string & nodePrefix,const internal::TimingNode & node,const bool isSubNode,const bool isLastSubnode,double parentTime,double totalTime)257 auto print_node(std::ostream& out, const std::vector<internal::Format> formats,
258 const std::size_t identifierSpace, const std::string& nodePrefix,
259 const internal::TimingNode& node, const bool isSubNode, const bool isLastSubnode,
260 double parentTime, double totalTime) -> void {
261 double sum, mean, median, min, max, lowerQuartile, upperQuartile;
262 std::tie(sum, mean, median, min, max, lowerQuartile, upperQuartile) =
263 calculate_statistic(node.timings);
264
265 if (!isSubNode) {
266 totalTime = sum;
267 parentTime = sum;
268 }
269
270 const double totalPercentage =
271 (totalTime < sum || totalTime == 0) ? 100.0 : sum / totalTime * 100.0;
272
273 const double parentPercentage =
274 (parentTime < sum || parentTime == 0) ? 100.0 : sum / parentTime * 100.0;
275
276 std::stringstream totalPercentageStream;
277 totalPercentageStream << std::fixed << std::setprecision(2) << totalPercentage;
278 std::stringstream parentPercentageStream;
279 parentPercentageStream << std::fixed << std::setprecision(2) << parentPercentage;
280
281 out << std::left << std::setw(identifierSpace);
282 if (isSubNode)
283 out << nodePrefix + "- " + node.identifier;
284 else
285 out << nodePrefix + node.identifier;
286
287 auto sortedTimings = node.timings;
288 std::sort(sortedTimings.begin(), sortedTimings.end());
289
290 const double currentTime = std::accumulate(sortedTimings.begin(), sortedTimings.end(), 0.0);
291 for (const auto& format : formats) {
292 print_stat(out, format, sortedTimings, totalTime, parentTime, currentTime);
293 }
294
295 out << std::endl;
296
297 for (const auto& subNode : node.subNodes) {
298 print_node(out, formats, identifierSpace, nodePrefix + std::string(" |"), subNode, true,
299 &subNode == &node.subNodes.back(), sum, totalTime);
300 if (!isLastSubnode && &subNode == &node.subNodes.back()) {
301 out << nodePrefix << std::endl;
302 }
303 }
304 }
305
306 // determine length of padding required for printing entire tree identifiers recursively
max_node_identifier_length(const internal::TimingNode & node,const std::size_t recursionDepth,const std::size_t addPerLevel,const std::size_t parentMax)307 auto max_node_identifier_length(const internal::TimingNode& node, const std::size_t recursionDepth,
308 const std::size_t addPerLevel, const std::size_t parentMax)
309 -> std::size_t {
310 std::size_t currentLength = node.identifier.length() + recursionDepth * addPerLevel;
311 std::size_t max = currentLength > parentMax ? currentLength : parentMax;
312 for (const auto& subNode : node.subNodes) {
313 const std::size_t subMax =
314 max_node_identifier_length(subNode, recursionDepth + 1, addPerLevel, max);
315 if (subMax > max) max = subMax;
316 }
317
318 return max;
319 }
320
export_node_json(const std::string & padding,const std::list<internal::TimingNode> & nodeList,std::ostream & stream)321 auto export_node_json(const std::string& padding, const std::list<internal::TimingNode>& nodeList,
322 std::ostream& stream) -> void {
323 stream << "{" << std::endl;
324 const std::string nodePadding = padding + " ";
325 const std::string subNodePadding = nodePadding + " ";
326 for (const auto& node : nodeList) {
327 stream << nodePadding << "\"" << node.identifier << "\" : {" << std::endl;
328 stream << subNodePadding << "\"timings\" : [";
329 for (const auto& value : node.timings) {
330 stream << value;
331 if (&value != &(node.timings.back())) stream << ", ";
332 }
333 stream << "]," << std::endl;
334 stream << subNodePadding << "\"sub-timings\" : ";
335 export_node_json(subNodePadding, node.subNodes, stream);
336 stream << nodePadding << "}";
337 if (&node != &(nodeList.back())) stream << ",";
338 stream << std::endl;
339 }
340 stream << padding << "}" << std::endl;
341 }
342
extract_timings(const std::string & identifier,const std::list<TimingNode> & nodes,std::vector<double> & timings)343 auto extract_timings(const std::string& identifier, const std::list<TimingNode>& nodes,
344 std::vector<double>& timings) -> void {
345 for (const auto& node : nodes) {
346 if (node.identifier == identifier) {
347 timings.insert(timings.end(), node.timings.begin(), node.timings.end());
348 }
349 extract_timings(identifier, node.subNodes, timings);
350 }
351 }
352
353 } // namespace
354 } // namespace internal
355
356 // ======================
357 // Timer
358 // ======================
process() const359 auto Timer::process() const -> TimingResult {
360 std::list<internal::TimingNode> results;
361 std::stringstream warnings;
362
363 try {
364 std::vector<internal::TimeStampPair> timePairs;
365 timePairs.reserve(timeStamps_.size() / 2);
366
367 // create pairs of start / stop timings
368 for (std::size_t i = 0; i < timeStamps_.size(); ++i) {
369 if (timeStamps_[i].type == internal::TimeStampType::Start) {
370 internal::TimeStampPair pair;
371 pair.startIdx = i;
372 pair.identifier = std::string(timeStamps_[i].identifierPtr);
373 std::size_t numInnerMatchingIdentifiers = 0;
374 // search for matching stop after start
375 for (std::size_t j = i + 1; j < timeStamps_.size(); ++j) {
376 // only consider matching identifiers
377 if (std::string(timeStamps_[j].identifierPtr) ==
378 std::string(timeStamps_[i].identifierPtr)) {
379 if (timeStamps_[j].type == internal::TimeStampType::Stop &&
380 numInnerMatchingIdentifiers == 0) {
381 // Matching stop found
382 std::chrono::duration<double> duration = timeStamps_[j].time - timeStamps_[i].time;
383 pair.time = duration.count();
384 pair.stopIdx = j;
385 timePairs.push_back(pair);
386 if (pair.time < 0) {
387 warnings << "rt_graph WARNING:Measured time is negative. Non-steady system-clock?!"
388 << std::endl;
389 }
390 break;
391 } else if (timeStamps_[j].type == internal::TimeStampType::Stop &&
392 numInnerMatchingIdentifiers > 0) {
393 // inner stop with matching identifier
394 --numInnerMatchingIdentifiers;
395 } else if (timeStamps_[j].type == internal::TimeStampType::Start) {
396 // inner start with matching identifier
397 ++numInnerMatchingIdentifiers;
398 }
399 }
400 }
401 if (pair.stopIdx == 0) {
402 warnings << "rt_graph WARNING: Start / stop time stamps do not match for \""
403 << timeStamps_[i].identifierPtr << "\"!" << std::endl;
404 }
405 }
406 }
407
408 // create tree of timings where sub-nodes represent timings fully enclosed by another start /
409 // stop pair Use the fact that timePairs is sorted by startIdx
410 for (std::size_t i = 0; i < timePairs.size(); ++i) {
411 auto& pair = timePairs[i];
412
413 // find potential parent by going backwards through pairs, starting with the current pair
414 // position
415 for (auto timePairIt = timePairs.rbegin() + (timePairs.size() - i);
416 timePairIt != timePairs.rend(); ++timePairIt) {
417 if (timePairIt->stopIdx > pair.stopIdx && timePairIt->nodePtr != nullptr) {
418 auto& parentNode = *(timePairIt->nodePtr);
419 // check if sub-node with identifier exists
420 bool nodeFound = false;
421 for (auto& subNode : parentNode.subNodes) {
422 if (subNode.identifier == pair.identifier) {
423 nodeFound = true;
424 subNode.timings.push_back(pair.time);
425 // mark node position in pair for finding sub-nodes
426 pair.nodePtr = &(subNode);
427 break;
428 }
429 }
430 if (!nodeFound) {
431 // create new sub-node
432 internal::TimingNode newNode;
433 newNode.identifier = pair.identifier;
434 newNode.timings.push_back(pair.time);
435 parentNode.subNodes.push_back(std::move(newNode));
436 // mark node position in pair for finding sub-nodes
437 pair.nodePtr = &(parentNode.subNodes.back());
438 }
439 break;
440 }
441 }
442
443 // No parent found, must be top level node
444 if (pair.nodePtr == nullptr) {
445 // Check if top level node with same name exists
446 for (auto& topNode : results) {
447 if (topNode.identifier == pair.identifier) {
448 topNode.timings.push_back(pair.time);
449 pair.nodePtr = &(topNode);
450 break;
451 }
452 }
453 }
454
455 // New top level node
456 if (pair.nodePtr == nullptr) {
457 internal::TimingNode newNode;
458 newNode.identifier = pair.identifier;
459 newNode.timings.push_back(pair.time);
460 // newNode.parent = nullptr;
461 results.push_back(std::move(newNode));
462
463 // mark node position in pair for finding sub-nodes
464 pair.nodePtr = &(results.back());
465 }
466 }
467 } catch (const std::exception& e) {
468 warnings << "rt_graph WARNING: Processing of timings failed: " << e.what() << std::endl;
469 } catch (...) {
470 warnings << "rt_graph WARNING: Processing of timings failed!" << std::endl;
471 }
472
473 return TimingResult(std::move(results), warnings.str());
474 }
475
476 // ======================
477 //
478 // ======================
479
json() const480 auto TimingResult::json() const -> std::string {
481 std::stringstream jsonStream;
482 jsonStream << std::scientific;
483 internal::export_node_json("", rootNodes_, jsonStream);
484 return jsonStream.str();
485 }
486
get_timings(const std::string & identifier) const487 auto TimingResult::get_timings(const std::string& identifier) const -> std::vector<double> {
488 std::vector<double> timings;
489 internal::extract_timings(identifier, rootNodes_, timings);
490 return timings;
491 }
492
print(std::vector<Stat> statistic) const493 auto TimingResult::print(std::vector<Stat> statistic) const -> std::string {
494 std::stringstream stream;
495
496 // print warnings
497 stream << warnings_;
498
499 // calculate space for printing identifiers
500 std::size_t identifierSpace = 0;
501 for (const auto& node : rootNodes_) {
502 const auto nodeMax = internal::max_node_identifier_length(node, 0, 2, identifierSpace);
503 if (nodeMax > identifierSpace) identifierSpace = nodeMax;
504 }
505 identifierSpace += 3;
506
507 auto totalSpace = identifierSpace;
508
509 std::vector<internal::Format> formats;
510 formats.reserve(statistic.size());
511 for (const auto& stat : statistic) {
512 formats.emplace_back(stat);
513 totalSpace += formats.back().space;
514 }
515
516 // Construct table header
517
518 // Table start
519 stream << std::string(totalSpace, '=') << std::endl;
520
521 // header
522 stream << std::right << std::setw(identifierSpace) << "";
523 for (const auto& format : formats) {
524 stream << std::right << std::setw(format.space) << format.header;
525 }
526 stream << std::endl;
527
528 // Header separation line
529 stream << std::string(totalSpace, '-') << std::endl;
530
531 // print all timings
532 for (const auto& node : rootNodes_) {
533 internal::print_node(stream, formats, identifierSpace, std::string(), node, false, true, 0.0,
534 0.0);
535 stream << std::endl;
536 }
537
538 // End table
539 stream << std::string(totalSpace, '=') << std::endl;
540
541 return stream.str();
542 }
543
544 } // namespace rt_graph
545
546