Validation/test/timing.cpp

0001 #include <iostream>
0002 #include <fstream>
0003 #include <iomanip>
0004 #include <string>
0005 #include <map>
0006 #include <cmath>
0007 #include <getopt.h>
0008 #include <sstream>
0009 #include <cstdlib>
0010
0011 int main(int argc, char **argv) {
0012   // http://manpages.ubuntu.com/manpages/intrepid/fr/man3/getopt.html
0013
0014   double factor = 0.995;
0015   std::string file = "TimingInfo.txt";
0016   int opt;
0017   std::string oval = "";
0018   while ((opt = getopt(argc, argv, "on:t:")) != -1) {
0019     switch (opt) {
0020       case 'n':
0021         file = std::string(optarg);
0022         break;
0023       case 't': {
0024         std::istringstream fraction(optarg);
0025         fraction >> factor;
0026         factor *= 0.01;
0027         break;
0028       }
0029       case 'o':
0030         oval = "[OVAL]";
0031         break;
0032       default:
0033         fprintf(stderr,
0034                 "Usage: %s -t [fraction of CPU in percentage] [-n filename TimingInfo.txt] [-o for oval] \n",
0035                 argv[0]);
0036         exit(EXIT_FAILURE);
0037     }
0038   }
0039
0040   std::cout << " Analyzing time report from " << file << " with CPU fraction correction " << factor << std::endl;
0041
0042   std::map<std::string, double> timingPerModule, timingPerLabel;
0043   std::map<unsigned, double> timingPerEvent;
0044   std::ifstream myTimingFile(file.c_str(), std::ifstream::in);
0045   std::string dummy1, label, module;
0046   double timing;
0047   unsigned idummy1, evt;
0048
0049   // If the machine is busy, the factor is not 100%.
0050   //  double factor = 0.995;
0051
0052   if (myTimingFile) {
0053     while (!myTimingFile.eof()) {
0054       myTimingFile >> dummy1 >> evt >> idummy1 >> label >> module >> timing;
0055       // std::cout << evt << " " << module << " " << timing << std::endl;
0056       timingPerEvent[evt] += timing * factor * 1000.;
0057       if (evt != 1) {
0058         timingPerModule[module] += timing * factor * 1000.;
0059         timingPerLabel[module + ":" + label] += timing * factor * 1000.;
0060       }
0061     }
0062   } else {
0063     std::cout << "File " << file << " does not exist!" << std::endl;
0064   }
0065
0066   std::map<std::string, double>::const_iterator modIt = timingPerModule.begin();
0067   std::map<std::string, double>::const_iterator labIt = timingPerLabel.begin();
0068   std::map<std::string, double>::const_iterator modEnd = timingPerModule.end();
0069   std::map<std::string, double>::const_iterator labEnd = timingPerLabel.end();
0070   std::map<double, std::string> modulePerTiming;
0071   std::map<double, std::string> labelPerTiming;
0072
0073   for (; modIt != modEnd; ++modIt) {
0074     double time = modIt->second / ((double)evt - 1.);
0075     std::string name = modIt->first;
0076     modulePerTiming[time] = name;
0077   }
0078
0079   for (; labIt != labEnd; ++labIt) {
0080     double time = labIt->second / ((double)evt - 1.);
0081     std::string name = labIt->first;
0082     labelPerTiming[time] = name;
0083   }
0084
0085   std::map<double, std::string>::const_reverse_iterator timeIt = modulePerTiming.rbegin();
0086   std::map<double, std::string>::const_reverse_iterator timeEnd = modulePerTiming.rend();
0087   std::map<double, std::string>::const_reverse_iterator timeIt2 = labelPerTiming.rbegin();
0088   std::map<double, std::string>::const_reverse_iterator timeEnd2 = labelPerTiming.rend();
0089
0090   std::cout << "Timing per module " << std::endl;
0091   std::cout << "================= " << std::endl;
0092   double totalTime = 0.;
0093   unsigned i = 1;
0094   for (; timeIt != timeEnd; ++timeIt) {
0095     totalTime += timeIt->first;
0096     std::cout << oval << " " << std::setw(3) << i++ << std::setw(50) << timeIt->second << " : " << std::setw(7)
0097               << std::setprecision(3) << timeIt->first << " ms/event" << std::endl;
0098   }
0099   std::cout << "Total time = " << totalTime << " ms/event " << std::endl;
0100
0101   std::cout << "================= " << std::endl;
0102   std::cout << "Timing per label  " << std::endl;
0103   std::cout << "================= " << std::endl;
0104   totalTime = 0.;
0105   i = 1;
0106   for (; timeIt2 != timeEnd2; ++timeIt2) {
0107     totalTime += timeIt2->first;
0108     std::cout << oval << " " << std::setw(3) << i++ << std::setw(100) << timeIt2->second << " : " << std::setw(7)
0109               << std::setprecision(3) << timeIt2->first << " ms/event" << std::endl;
0110   }
0111   std::cout << "================= " << std::endl;
0112   std::cout << "Total time = " << totalTime << " ms/event " << std::endl;
0113
0114   std::map<unsigned, double>::const_iterator eventIt = timingPerEvent.begin();
0115   std::map<unsigned, double>::const_iterator eventEnd = timingPerEvent.end();
0116   double minEv = 9999.;
0117   double maxEv = 0.;
0118   double rms = 0.;
0119   double mean = 0.;
0120
0121   for (; eventIt != eventEnd; ++eventIt) {
0122     if (eventIt->first == 1)
0123       continue;
0124     double timeEv = eventIt->second;
0125     if (eventIt->second > maxEv)
0126       maxEv = timeEv;
0127     if (eventIt->second < minEv)
0128       minEv = timeEv;
0129     mean += timeEv;
0130     rms += timeEv * timeEv;
0131   }
0132
0133   mean /= (double)evt - 1.;
0134   rms /= (double)evt - 1.;
0135   rms = std::sqrt(rms - mean * mean);
0136   std::cout << "Total time = " << mean << " +/- " << rms << " ms/event" << std::endl;
0137   std::cout << "Min.  time = " << minEv << " ms/event" << std::endl;
0138   std::cout << "Max.  time = " << maxEv << " ms/event" << std::endl;
0139 }