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       {
0025     std::istringstream fraction(optarg);
0026     fraction >> factor;
0027     factor*=0.01;
0028     break    ;
0029       }
0030     case 'o':
0031       oval="[OVAL]" ;
0032       break;
0033     default:
0034       fprintf(stderr, "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
0096     totalTime += timeIt->first;
0097     std::cout << oval << " " << std::setw(3) << i++
0098           << std::setw(50) << timeIt->second << " : "
0099           << std::setw(7) << std::setprecision(3) << timeIt-> first << " ms/event"
0100           << std::endl;
0101   }
0102   std::cout << "Total time = " << totalTime << " ms/event " << std::endl;
0103
0104   std::cout << "================= " << std::endl;
0105   std::cout << "Timing per label  " << std::endl;
0106   std::cout << "================= " << std::endl;
0107   totalTime = 0.;
0108   i = 1;
0109   for ( ; timeIt2 != timeEnd2; ++timeIt2 ) {
0110
0111     totalTime += timeIt2->first;
0112     std::cout << oval << " " << std::setw(3) << i++
0113           << std::setw(100) << timeIt2->second << " : "
0114           << std::setw(7) << std::setprecision(3) << timeIt2-> first << " ms/event"
0115           << std::endl;
0116   }
0117   std::cout << "================= " << std::endl;
0118   std::cout << "Total time = " << totalTime << " ms/event " << std::endl;
0119
0120   std::map<unsigned,double>::const_iterator eventIt = timingPerEvent.begin();
0121   std::map<unsigned,double>::const_iterator eventEnd = timingPerEvent.end();
0122   double minEv = 9999.;
0123   double maxEv = 0.;
0124   double rms = 0.;
0125   double mean = 0.;
0126
0127   for ( ; eventIt != eventEnd; ++eventIt ) {
0128     if ( eventIt->first == 1 ) continue;
0129     double timeEv = eventIt->second;
0130     if ( eventIt->second > maxEv ) maxEv = timeEv;
0131     if ( eventIt->second < minEv ) minEv = timeEv;
0132     mean += timeEv;
0133     rms += timeEv*timeEv;
0134   }
0135
0136   mean /= (double)evt-1.;
0137   rms /= (double)evt-1.;
0138   rms = std::sqrt(rms-mean*mean);
0139   std::cout << "Total time = " << mean << " +/- " << rms << " ms/event" << std::endl;
0140   std::cout << "Min.  time = " << minEv << " ms/event" << std::endl;
0141   std::cout << "Max.  time = " << maxEv << " ms/event" << std::endl;
0142 }
0143