MessageService/src/ELstatistics.cc

0001 //  ---------------------------------------------------------------------
0002 //
0003 // ELstatistics.cc
0004 //
0005 // History:
0006 //   7/8/98     mf      Created
0007 //   7/2/99     jv      Added noTerminationSummary() function
0008 //   6/7/00     web     Reflect consolidation of ELdestination/X;
0009 //                      consolidate ELstatistics/X
0010 //   6/14/00    web     Remove GNU relic code
0011 //   6/15/00    web     using -> USING
0012 //   10/4/00    mf      filterModule() and excludeModule()
0013 //   3/13/00    mf      statisticsMap()
0014 //    4/4/01    mf      Simplify filter/exclude logic by useing base class
0015 //                      method thisShouldBeIgnored().  Eliminate
0016 //                      moduleOfinterest and moduleToexclude.
0017 //  11/01/01    web     Remove last vestige of GNU relic code; reordered
0018 //                      initializers to correspond to order of member
0019 //                      declarations
0020 //   1/17/06    mf  summary() for use in MessageLogger
0021 //   8/16/07    mf  Changes to implement grouping of modules in specified
0022 //          categories
0023 //   6/19/08    mf  summaryForJobReport()
0024 //
0025 //  ---------------------------------------------------------------------
0026
0027 #include "FWCore/MessageService/src/ELstatistics.h"
0028
0029 #include "FWCore/MessageLogger/interface/ErrorObj.h"
0030
0031 #include <iostream>
0032 #include <iomanip>
0033 #include <sstream>
0034 #include <ios>
0035 #include <cassert>
0036
0037 // Possible Traces:
0038 // #define ELstatisticsCONSTRUCTOR_TRACE
0039 // #define ELstatsLOG_TRACE
0040
0041 namespace {
0042   std::string summarizeContext(const std::string& c) {
0043     if (c.substr(0, 4) != "Run:")
0044       return c;
0045     std::istringstream is(c);
0046     std::string runWord;
0047     int run;
0048     is >> runWord >> run;
0049     if (!is)
0050       return c;
0051     if (runWord != "Run:")
0052       return c;
0053     std::string eventWord;
0054     int event;
0055     is >> eventWord >> event;
0056     if (!is)
0057       return c;
0058     if (eventWord != "Event:")
0059       return c;
0060     std::ostringstream os;
0061     os << run << "/" << event;
0062     return os.str();
0063   }
0064 }  // namespace
0065
0066 using namespace edm::messagelogger;
0067
0068 namespace edm {
0069   namespace service {
0070
0071     // ----------------------------------------------------------------------
0072     // Constructors
0073     // ----------------------------------------------------------------------
0074
0075     ELstatistics::ELstatistics()
0076         : ELdestination(),
0077           tableLimit(-1),
0078           stats(),
0079           updatedStats(false),
0080           termStream(std::cerr),
0081           printAtTermination(true) {
0082 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0083       std::cerr << "Constructor for ELstatistics()\n";
0084 #endif
0085
0086     }  // ELstatistics()
0087
0088     ELstatistics::ELstatistics(std::ostream& osp)
0089         : ELdestination(), tableLimit(-1), stats(), updatedStats(false), termStream(osp), printAtTermination(true) {
0090 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0091       std::cerr << "Constructor for ELstatistics(osp)\n";
0092 #endif
0093
0094     }  // ELstatistics()
0095
0096     ELstatistics::ELstatistics(int spaceLimit)
0097         : ELdestination(),
0098           tableLimit(spaceLimit),
0099           stats(),
0100           updatedStats(false),
0101           termStream(std::cerr),
0102           printAtTermination(true) {
0103 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0104       std::cerr << "Constructor for ELstatistics(spaceLimit)\n";
0105 #endif
0106
0107     }  // ELstatistics()
0108
0109     ELstatistics::ELstatistics(int spaceLimit, std::ostream& osp)
0110         : ELdestination(),
0111           tableLimit(spaceLimit),
0112           stats(),
0113           updatedStats(false),
0114           termStream(osp),
0115           printAtTermination(true) {
0116 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0117       std::cerr << "Constructor for ELstatistics(spaceLimit,osp)\n";
0118 #endif
0119
0120     }  // ELstatistics()
0121
0122     ELstatistics::ELstatistics(const ELstatistics& orig)
0123         : ELdestination(),
0124           tableLimit(orig.tableLimit),
0125           stats(orig.stats),
0126           updatedStats(orig.updatedStats),
0127           termStream(orig.termStream),
0128           printAtTermination(orig.printAtTermination) {
0129 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0130       std::cerr << "Copy constructor for ELstatistics()\n";
0131 #endif
0132
0133       ignoreMostModules = orig.ignoreMostModules;
0134       respondToThese = orig.respondToThese;
0135       respondToMostModules = orig.respondToMostModules;
0136       ignoreThese = orig.ignoreThese;
0137
0138     }  // ELstatistics()
0139
0140     ELstatistics::~ELstatistics() {
0141 #ifdef ELstatisticsCONSTRUCTOR_TRACE
0142       std::cerr << "Destructor for ELstatistics\n";
0143 #endif
0144
0145       if (updatedStats && printAtTermination)
0146         summary(termStream, "Termination Summary");
0147
0148     }  // ~ELstatistics()
0149
0150     // ----------------------------------------------------------------------
0151     // Methods invoked by the ELadministrator
0152     // ----------------------------------------------------------------------
0153
0154     bool ELstatistics::log(const edm::ErrorObj& msg) {
0155 #ifdef ELstatsLOG_TRACE
0156       std::cerr << "  =:=:=: Log to an ELstatistics\n";
0157 #endif
0158
0159       // See if this message is to be counted.
0160
0161       if (msg.xid().severity < threshold)
0162         return false;
0163       if (thisShouldBeIgnored(msg.xid().module))
0164         return false;
0165
0166       // Account for this message, making a new table entry if needed:
0167       //
0168       ELmap_stats::iterator s = stats.find(msg.xid());
0169       if (s == stats.end()) {
0170         if (tableLimit < 0 || static_cast<int>(stats.size()) < tableLimit) {
0171           stats[msg.xid()] = StatsCount();
0172           s = stats.find(msg.xid());
0173         }
0174       }
0175 #ifdef ELstatsLOG_TRACE
0176       std::cerr << "    =:=:=: Message accounted for in stats \n";
0177 #endif
0178       if (s != stats.end()) {
0179         (*s).second.add(summarizeContext(msg.context()), msg.reactedTo());
0180
0181         updatedStats = true;
0182 #ifdef ELstatsLOG_TRACE
0183         std::cerr << "    =:=:=: Updated stats \n";
0184 #endif
0185       }
0186
0187       // For the purposes of telling whether any log destination has reacted
0188       // to the message, the statistics destination does not count:
0189       //
0190
0191 #ifdef ELstatsLOG_TRACE
0192       std::cerr << "  =:=:=: log(msg) done (stats) \n";
0193 #endif
0194
0195       return false;
0196
0197     }  // log()
0198
0199     void ELstatistics::clearSummary() {
0200       limits.zero();
0201       ELmap_stats::iterator s;
0202       for (s = stats.begin(); s != stats.end(); ++s) {
0203         (*s).second.n = 0;
0204         (*s).second.context1 = (*s).second.context2 = (*s).second.contextLast = "";
0205       }
0206
0207     }  // clearSummary()
0208
0209     void ELstatistics::wipe() {
0210       limits.wipe();
0211       stats.erase(stats.begin(), stats.end());  //stats.clear();
0212
0213     }  // wipe()
0214
0215     void ELstatistics::zero() { limits.zero(); }  // zero()
0216
0217     std::string ELstatistics::formSummary(ELmap_stats& stats) {
0218       // Major changes 8/16/07 mf, including making this
0219       // a static member function instead of a free function
0220
0221       using std::ios; /* _base ? */
0222       using std::left;
0223       using std::right;
0224       using std::setw;
0225
0226       std::ostringstream s;
0227       int n = 0;
0228
0229       // -----  Summary part I:
0230       //
0231       bool ftnote(false);
0232
0233       struct part3 {
0234         long n, t;
0235         part3() : n(0L), t(0L) { ; }
0236       } p3[ELseverityLevel::nLevels];
0237
0238       std::set<std::string>::iterator gcEnd = groupedCategories.end();
0239       std::set<std::string> gCats = groupedCategories;  // TEMP FOR DEBUGGING SANITY
0240       for (ELmap_stats::const_iterator i = stats.begin(); i != stats.end(); ++i) {
0241         // If this is a grouped category, wait till later to output its stats
0242         std::string cat = (*i).first.id;
0243         if (groupedCategories.find(cat) != gcEnd) {  // 8/16/07 mf
0244           continue;                                  // We will process these categories later
0245         }
0246
0247         // -----  Emit new process and part I header, if needed:
0248         //
0249         if (n == 0) {
0250           s << "\n";
0251           s << " type     category        sev    module        "
0252                "subroutine        count    total\n"
0253             << " ---- -------------------- -- ---------------- "
0254                "----------------  -----    -----\n";
0255         }
0256         // -----  Emit detailed message information:
0257         //
0258         s << right << std::setw(5) << ++n << ' ' << left << std::setw(20) << (*i).first.id.substr(0, 20) << ' ' << left
0259           << std::setw(2) << (*i).first.severity.getSymbol() << ' ' << left << std::setw(16)
0260           << (*i).first.module.substr(0, 16) << ' ' << left << std::setw(16) << (*i).first.subroutine.substr(0, 16)
0261           << right << std::setw(7) << (*i).second.n << left << std::setw(1) << ((*i).second.ignoredFlag ? '*' : ' ')
0262           << right << std::setw(8) << (*i).second.aggregateN << '\n';
0263         ftnote = ftnote || (*i).second.ignoredFlag;
0264
0265         // -----  Obtain information for Part III, below:
0266         //
0267         ELextendedID xid = (*i).first;
0268         p3[xid.severity.getLevel()].n += (*i).second.n;
0269         p3[xid.severity.getLevel()].t += (*i).second.aggregateN;
0270       }  // for i
0271
0272       // ----- Part Ia:  The grouped categories
0273       for (std::set<std::string>::iterator g = groupedCategories.begin(); g != gcEnd; ++g) {
0274         int groupTotal = 0;
0275         int groupAggregateN = 0;
0276         ELseverityLevel severityLevel;
0277         bool groupIgnored = true;
0278         for (ELmap_stats::const_iterator i = stats.begin(); i != stats.end(); ++i) {
0279           if ((*i).first.id == *g) {
0280             if (groupTotal == 0)
0281               severityLevel = (*i).first.severity;
0282             groupIgnored &= (*i).second.ignoredFlag;
0283             groupAggregateN += (*i).second.aggregateN;
0284             ++groupTotal;
0285           }
0286         }  // for i
0287         if (groupTotal > 0) {
0288           // -----  Emit detailed message information:
0289           //
0290           s << right << std::setw(5) << ++n << ' ' << left << std::setw(20) << (*g).substr(0, 20) << ' ' << left
0291             << std::setw(2) << severityLevel.getSymbol() << ' ' << left << std::setw(16) << "  <Any Module>  " << ' '
0292             << left << std::setw(16) << "<Any Function>" << right << std::setw(7) << groupTotal << left << std::setw(1)
0293             << (groupIgnored ? '*' : ' ') << right << std::setw(8) << groupAggregateN << '\n';
0294           ftnote = ftnote || groupIgnored;
0295
0296           // -----  Obtain information for Part III, below:
0297           //
0298           int lev = severityLevel.getLevel();
0299           p3[lev].n += groupTotal;
0300           p3[lev].t += groupAggregateN;
0301         }  // end if groupTotal>0
0302       }    // for g
0303
0304       // -----  Provide footnote to part I, if needed:
0305       //
0306       if (ftnote)
0307         s << "\n* Some occurrences of this message"
0308              " were suppressed in all logs, due to limits.\n";
0309
0310       // -----  Summary part II:
0311       //
0312       n = 0;
0313       for (ELmap_stats::const_iterator i = stats.begin(); i != stats.end(); ++i) {
0314         std::string cat = (*i).first.id;
0315         if (groupedCategories.find(cat) != gcEnd) {  // 8/16/07 mf
0316           continue;                                  // We will process these categories later
0317         }
0318         if (n == 0) {
0319           s << '\n'
0320             << " type    category    Examples: "
0321                "run/evt        run/evt          run/evt\n"
0322             << " ---- -------------------- ----"
0323                "------------ ---------------- ----------------\n";
0324         }
0325         s << right << std::setw(5) << ++n << ' ' << left << std::setw(20) << (*i).first.id.c_str() << ' ' << left
0326           << std::setw(16) << (*i).second.context1.c_str() << ' ' << left << std::setw(16)
0327           << (*i).second.context2.c_str() << ' ' << (*i).second.contextLast.c_str() << '\n';
0328       }  // for
0329
0330       // -----  Summary part III:
0331       //
0332       s << "\nSeverity    # Occurrences   Total Occurrences\n"
0333         << "--------    -------------   -----------------\n";
0334       for (int k = 0; k < ELseverityLevel::nLevels; ++k) {
0335         if (p3[k].n != 0 || p3[k].t != 0) {
0336           s << left << std::setw(8) << ELseverityLevel(ELseverityLevel::ELsev_(k)).getName().c_str() << right
0337             << std::setw(17) << p3[k].n << right << std::setw(20) << p3[k].t << '\n';
0338         }
0339       }  // for
0340
0341       return s.str();
0342
0343     }  // formSummary()
0344
0345     void ELstatistics::summary(std::ostream& os, std::string_view title) {
0346       os << title << std::endl << formSummary(stats) << std::flush;
0347       updatedStats = false;
0348
0349     }  // summary()
0350
0351     void ELstatistics::summary(unsigned long overfullWaitCount) {
0352       termStream << "\n=============================================\n\n"
0353                  << "MessageLogger Summary" << std::endl
0354                  << formSummary(stats) << std::endl
0355                  << "dropped waiting message count " << overfullWaitCount << std::endl
0356                  << std::flush;
0357       updatedStats = false;
0358
0359     }  // summary()
0360
0361     void ELstatistics::noTerminationSummary() { printAtTermination = false; }
0362
0363     std::map<ELextendedID, StatsCount> ELstatistics::statisticsMap() const {
0364       return std::map<ELextendedID, StatsCount>(stats);
0365     }
0366
0367     // 6/19/08 mf
0368     void ELstatistics::summaryForJobReport(std::map<std::string, double>& sm) {
0369       struct part3 {
0370         long n, t;
0371         part3() : n(0L), t(0L) { ; }
0372       } p3[ELseverityLevel::nLevels];
0373
0374       std::set<std::string>::iterator gcEnd = groupedCategories.end();
0375       std::set<std::string> gCats = groupedCategories;  // TEMP FOR DEBUGGING SANITY
0376
0377       // ----- Part I:  The ungrouped categories
0378       for (ELmap_stats::const_iterator i = stats.begin(); i != stats.end(); ++i) {
0379         // If this is a grouped category, wait till later to output its stats
0380         std::string cat = (*i).first.id;
0381         if (groupedCategories.find(cat) != gcEnd) {
0382           continue;  // We will process these categories later
0383         }
0384
0385         // -----  Emit detailed message information:
0386         //
0387         std::ostringstream s;
0388         s << "Category_";
0389         std::string sevSymbol = (*i).first.severity.getSymbol();
0390         if (sevSymbol[0] == '-')
0391           sevSymbol = sevSymbol.substr(1);
0392         s << sevSymbol << "_" << (*i).first.id;
0393         int n = (*i).second.aggregateN;
0394         std::string catstr = s.str();
0395         if (sm.find(catstr) != sm.end()) {
0396           sm[catstr] += n;
0397         } else {
0398           sm[catstr] = n;
0399         }
0400         // -----  Obtain information for Part III, below:
0401         //
0402         ELextendedID xid = (*i).first;
0403         p3[xid.severity.getLevel()].n += (*i).second.n;
0404         p3[xid.severity.getLevel()].t += (*i).second.aggregateN;
0405       }  // for i
0406
0407       // ----- Part Ia:  The grouped categories
0408       for (std::set<std::string>::iterator g = groupedCategories.begin(); g != gcEnd; ++g) {
0409         int groupTotal = 0;
0410         int groupAggregateN = 0;
0411         ELseverityLevel severityLevel;
0412         for (ELmap_stats::const_iterator i = stats.begin(); i != stats.end(); ++i) {
0413           if ((*i).first.id == *g) {
0414             if (groupTotal == 0)
0415               severityLevel = (*i).first.severity;
0416             groupAggregateN += (*i).second.aggregateN;
0417             ++groupTotal;
0418           }
0419         }  // for i
0420         if (groupTotal > 0) {
0421           // -----  Emit detailed message information:
0422           //
0423           std::ostringstream s;
0424           s << "Category_";
0425           std::string sevSymbol = severityLevel.getSymbol();
0426           if (sevSymbol[0] == '-')
0427             sevSymbol = sevSymbol.substr(1);
0428           s << sevSymbol << "_" << *g;
0429           int n = groupAggregateN;
0430           std::string catstr = s.str();
0431           if (sm.find(catstr) != sm.end()) {
0432             sm[catstr] += n;
0433           } else {
0434             sm[catstr] = n;
0435           }
0436
0437           // -----  Obtain information for Part III, below:
0438           //
0439           int lev = severityLevel.getLevel();
0440           p3[lev].n += groupTotal;
0441           p3[lev].t += groupAggregateN;
0442         }  // end if groupTotal>0
0443       }    // for g
0444
0445       // part II (sample event numbers) does not exist for the job report.
0446
0447       // -----  Summary part III:
0448       //
0449       for (int k = 0; k < ELseverityLevel::nLevels; ++k) {
0450         //if ( p3[k].t != 0 )  {
0451         if (true) {
0452           std::string sevName;
0453           sevName = ELseverityLevel(ELseverityLevel::ELsev_(k)).getName();
0454           if (sevName == "Severe")
0455             sevName = "System";
0456           if (sevName == "Success")
0457             sevName = "Debug";
0458           sevName = std::string("Log") + sevName;
0459           sevName = dualLogName(sevName);
0460           if (sevName != "UnusedSeverity") {
0461             sm[sevName] = p3[k].t;
0462           }
0463         }
0464       }  // for k
0465
0466     }  // summaryForJobReport()
0467
0468     std::string ELstatistics::dualLogName(std::string const& s) {
0469       if (s == "LogDebug")
0470         return "LogDebug_LogTrace";
0471       if (s == "LogInfo")
0472         return "LogInfo_LogVerbatim";
0473       if (s == "LogWarning")
0474         return "LogWarnng_LogPrint";
0475       if (s == "LogError")
0476         return "LogError_LogProblem";
0477       if (s == "LogSystem")
0478         return "LogSystem_LogAbsolute";
0479       return "UnusedSeverity";
0480     }
0481
0482     std::set<std::string> ELstatistics::groupedCategories;  // 8/16/07 mf
0483
0484     void ELstatistics::noteGroupedCategory(std::string const& cat) { groupedCategories.insert(cat); }
0485
0486   }  // end of namespace service
0487 }  // end of namespace edm