MessageService/src/ELoutput.cc

0001 // ----------------------------------------------------------------------
0002 //
0003 // ELoutput.cc
0004 //
0005 //
0006 // 7/8/98       mf      Created
0007 // 6/10/99      jv      JV:1 puts a \n after each log using suppressContext()
0008 // 6/11/99      jv      JV:2 accounts for newline at the beginning and end of
0009 //                           an emitted ELstring
0010 // 6/14/99      mf      Made the static char* in formatTime into auto so that
0011 //                      ctime(&t) is called each time - corrects the bug of
0012 //                      never changing the first timestamp.
0013 // 6/15/99      mf      Inserted operator<<(void (*f)(ErrorLog&) to avoid
0014 //                      mystery characters being inserted when users <<
0015 //                      endmsg to an ErrorObj.
0016 // 7/2/99       jv      Added separate/attachTime, Epilogue, and Serial options
0017 // 8/2/99       jv      Modified handling of newline in an emmitted ELstring
0018 // 2/22/00      mf      Changed usage of myDestX to myOutputX.  Added
0019 //                      constructor of ELoutput from ELoutputX * to allow for
0020 //                      inheritance.
0021 // 6/7/00       web     Reflect consolidation of ELdestination/X; consolidate
0022 //                      ELoutput/X; add filterModule() and query logic
0023 // 10/4/00      mf      excludeModule()
0024 // 1/15/01      mf      line length control: changed ELoutputLineLen to
0025 //                      the base class lineLen (no longer static const)
0026 // 2/13/01      mf      Added emitAtStart argument to two constructors
0027 //                      { Enh 001 }.
0028 // 4/4/01       mf      Simplify filter/exclude logic by useing base class
0029 //                      method thisShouldBeIgnored().  Eliminate
0030 //                      moduleOfinterest and moduleToexclude.
0031 // 6/15/01      mf      Repaired Bug 005 by explicitly setting all
0032 //                      ELdestination member data appropriately.
0033 //10/18/01      mf      When epilogue not on separate line, preceed by space
0034 // 6/23/03      mf      changeFile(), flush()
0035 // 4/09/04      mf      Add 1 to length in strftime call in formatTime, to
0036 //                      correctly provide the time zone.  Had been providing
0037 //                      CST every time.
0038 //
0039 // 12/xx/06     mf  Tailoring to CMS MessageLogger
0040 //  1/11/06 mf      Eliminate time stamp from starting message
0041 //  3/20/06 mf  Major formatting change to do no formatting
0042 //          except the header and line separation.
0043 //  4/04/06 mf  Move the line feed between header and text
0044 //          till after the first 3 items (FILE:LINE) for
0045 //          debug messages.
0046 //  6/06/06 mf  Verbatim
0047 //  6/12/06 mf  Set preambleMode true when printing the header
0048 //
0049 // Change Log
0050 //
0051 //  1 10/18/06  mf  In format_time(): Initialized ts[] with 5 extra
0052 //          spaces, to cover cases where time zone is more than
0053 //          3 characters long
0054 //
0055 //  2 10/30/06  mf  In log():  if severity indicated is SEVERE, do not
0056 //          impose limits.  This is to implement the LogSystem
0057 //          feature:  Those messages are never to be ignored.
0058 //
0059 //  3 6/11/07  mf   In emitToken():  In preamble mode, do not break and indent
0060 //          even if exceeding nominal line length.
0061 //
0062 //  4 6/11/07  mf   In log():  After the message, add a %MSG on its own line
0063 //
0064 //  5 3/27/09  mf   Properly treat charsOnLine, which had been fouled due to
0065 //          change 3.  In log() and emitToken().
0066 //
0067 //  6 9/2/10  mf    Initialize preambleMode in each ctor, and remove the
0068 //          unnecessary use of tprm which was preserving a moot
0069 //          initial value.
0070 //
0071 //  7 9/30/10 wmtan make formatTime() thread safe by not using statics.
0072 //
0073 // ----------------------------------------------------------------------
0074
0075 #include "FWCore/MessageService/src/ELoutput.h"
0076
0077 #include "FWCore/MessageLogger/interface/ErrorObj.h"
0078
0079 #include "FWCore/Utilities/interface/do_nothing_deleter.h"
0080
0081 // Possible Traces:
0082 // #define ELoutputCONSTRUCTOR_TRACE
0083 // #define ELoutputTRACE_LOG
0084 // #define ELoutput_EMIT_TRACE
0085
0086 #include <cassert>
0087 #include <cstring>
0088 #include <fstream>
0089 #include <iostream>
0090 #include <memory>
0091
0092 namespace {
0093   // ----------------------------------------------------------------------
0094   // Useful function:
0095   // ----------------------------------------------------------------------
0096
0097   std::string formatTime(const time_t t) {  // Change log 7
0098
0099     constexpr char dummy[] = "dd-Mon-yyyy hh:mm:ss TZN     ";  // Change log 7 for length only
0100     char ts[sizeof(dummy)];                                    // Change log 7
0101
0102     struct tm timebuf;  // Change log 7
0103
0104     strftime(ts, sizeof(dummy), "%d-%b-%Y %H:%M:%S %Z", localtime_r(&t, &timebuf));  // Change log 7
0105                                                                                      // mf 4-9-04
0106
0107 #ifdef STRIP_TRAILING_BLANKS_IN_TIMEZONE
0108     // strip trailing blanks that would come when the time zone is not as
0109     // long as the maximum allowed - probably not worth the time
0110     unsigned int b = strlen(ts);
0111     while (ts[--b] == ' ') {
0112       ts[b] = 0;
0113     }
0114 #endif
0115
0116     return std::string(ts);  // Change log 7
0117   }  // formatTime()
0118 }  // namespace
0119
0120 using namespace edm::messagelogger;
0121 namespace edm {
0122   namespace service {
0123     // ----------------------------------------------------------------------
0124     // Constructors:
0125     // ----------------------------------------------------------------------
0126
0127     ELoutput::ELoutput()
0128         : ELdestination(),
0129           os(&std::cerr, do_nothing_deleter()),
0130           charsOnLine(0),
0131           xid(),
0132           wantTimestamp(true),
0133           wantModule(true),
0134           wantSubroutine(true),
0135           wantText(true),
0136           wantSomeContext(true),
0137           wantSerial(false),
0138           wantFullContext(false),
0139           wantTimeSeparate(false),
0140           wantEpilogueSeparate(false),
0141           preambleMode(true)  // 006 9/2/10 mf
0142     {
0143 #ifdef ELoutputCONSTRUCTOR_TRACE
0144       std::cerr << "Constructor for ELoutput()\n";
0145 #endif
0146
0147       emitToken("\n=================================================", true);
0148       emitToken("\nMessage Log File written by MessageLogger service \n");
0149       emitToken("\n=================================================\n", true);
0150
0151     }  // ELoutput()
0152
0153     ELoutput::ELoutput(std::ostream& os_, bool emitAtStart)
0154         : ELdestination(),
0155           os(&os_, do_nothing_deleter()),
0156           charsOnLine(0),
0157           xid(),
0158           wantTimestamp(true),
0159           wantModule(true),
0160           wantSubroutine(true),
0161           wantText(true),
0162           wantSomeContext(true),
0163           wantSerial(false),
0164           wantFullContext(false),
0165           wantTimeSeparate(false),
0166           wantEpilogueSeparate(false),
0167           preambleMode(true)  // 006 9/2/10 mf
0168     {
0169 #ifdef ELoutputCONSTRUCTOR_TRACE
0170       std::cerr << "Constructor for ELoutput( os )\n";
0171 #endif
0172
0173       // Enh 001 2/13/01 mf
0174       if (emitAtStart) {
0175         preambleMode = true;
0176         emitToken("\n=================================================", true);
0177         emitToken("\nMessage Log File written by MessageLogger service \n");
0178         emitToken("\n=================================================\n", true);
0179       }
0180
0181     }  // ELoutput()
0182
0183     ELoutput::ELoutput(const std::string& fileName, bool emitAtStart)
0184         : ELdestination(),
0185           os(new std::ofstream(fileName.c_str(), std::ios /*_base*/ ::app), close_and_delete()),
0186           charsOnLine(0),
0187           xid(),
0188           wantTimestamp(true),
0189           wantModule(true),
0190           wantSubroutine(true),
0191           wantText(true),
0192           wantSomeContext(true),
0193           wantSerial(false),
0194           wantFullContext(false),
0195           wantTimeSeparate(false),
0196           wantEpilogueSeparate(false),
0197           preambleMode(true)  // 006 9/2/10 mf
0198     {
0199 #ifdef ELoutputCONSTRUCTOR_TRACE
0200       std::cerr << "Constructor for ELoutput( " << fileName << " )\n";
0201 #endif
0202
0203       preambleMode = true;
0204       if (os && *os) {
0205 #ifdef ELoutputCONSTRUCTOR_TRACE
0206         std::cerr << "          Testing if os is owned\n";
0207 #endif
0208 #ifdef ELoutputCONSTRUCTOR_TRACE
0209         std::cerr << "          About to do first emit\n";
0210 #endif
0211         // Enh 001 2/13/01 mf
0212         if (emitAtStart) {
0213           emitToken("\n=======================================================", true);
0214           emitToken("\nError Log File ");
0215           emitToken(fileName);
0216           emitToken(" \n");
0217         }
0218       } else {
0219 #ifdef ELoutputCONSTRUCTOR_TRACE
0220         std::cerr << "          Deleting os\n";
0221 #endif
0222         os.reset(&std::cerr, do_nothing_deleter());
0223 #ifdef ELoutputCONSTRUCTOR_TRACE
0224         std::cerr << "          about to emit to cerr\n";
0225 #endif
0226         if (emitAtStart) {
0227           emitToken("\n=======================================================", true);
0228           emitToken("\n%MSG** Logging to cerr is being substituted");
0229           emitToken(" for specified log file \"");
0230           emitToken(fileName);
0231           emitToken("\" which could not be opened for write or append.\n");
0232         }
0233       }
0234       if (emitAtStart) {
0235         std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0236         emitToken(ftime, true);
0237         emitToken("\n=======================================================\n", true);
0238       }
0239       // preambleMode = tprm; removed 9/2/10 mf see change log 6
0240
0241 #ifdef ELoutputCONSTRUCTOR_TRACE
0242       std::cerr << "Constructor for ELoutput completed.\n";
0243 #endif
0244
0245     }  // ELoutput()
0246
0247     ELoutput::ELoutput(const ELoutput& orig)
0248         : ELdestination(),
0249           os(orig.os),
0250           charsOnLine(orig.charsOnLine),
0251           xid(orig.xid),
0252           wantTimestamp(orig.wantTimestamp),
0253           wantModule(orig.wantModule),
0254           wantSubroutine(orig.wantSubroutine),
0255           wantText(orig.wantText),
0256           wantSomeContext(orig.wantSomeContext),
0257           wantSerial(orig.wantSerial),
0258           wantFullContext(orig.wantFullContext),
0259           wantTimeSeparate(orig.wantTimeSeparate),
0260           wantEpilogueSeparate(orig.wantEpilogueSeparate),
0261           preambleMode(orig.preambleMode)  // 006 9/2/10 mf
0262     {
0263 #ifdef ELoutputCONSTRUCTOR_TRACE
0264       std::cerr << "Copy constructor for ELoutput\n";
0265 #endif
0266
0267       // mf 6/15/01 fix of Bug 005
0268       threshold = orig.threshold;
0269       traceThreshold = orig.traceThreshold;
0270       limits = orig.limits;
0271       preamble = orig.preamble;
0272       newline = orig.newline;
0273       indent = orig.indent;
0274       lineLength = orig.lineLength;
0275
0276       ignoreMostModules = orig.ignoreMostModules;
0277       respondToThese = orig.respondToThese;
0278       respondToMostModules = orig.respondToMostModules;
0279       ignoreThese = orig.ignoreThese;
0280
0281     }  // ELoutput()
0282
0283     ELoutput::~ELoutput() {
0284 #ifdef ELoutputCONSTRUCTOR_TRACE
0285       std::cerr << "Destructor for ELoutput\n";
0286 #endif
0287
0288     }  // ~ELoutput()
0289
0290     // ----------------------------------------------------------------------
0291     // Methods invoked by the ELadministrator:
0292     // ----------------------------------------------------------------------
0293
0294     //#define THRESHTRACE
0295     //#define ELoutputTRACE_LOG
0296
0297     bool ELoutput::log(const edm::ErrorObj& msg) {
0298 #ifdef ELoutputTRACE_LOG
0299       std::cerr << "    =:=:=: Log to an ELoutput \n";
0300 #endif
0301
0302       xid = msg.xid();  // Save the xid.
0303
0304 #ifdef THRESHTRACE
0305       std::cerr << "    =:=:=: Log to an ELoutput \n"
0306                 << "           severity  = " << xid.severity << "\n"
0307                 << "           threshold = " << threshold << "\n"
0308                 << "           id        = " << xid.id << "\n";
0309 #endif
0310
0311       // See if this message is to be acted upon, and add it to limits table
0312       // if it was not already present:
0313       //
0314       if (xid.severity < threshold)
0315         return false;
0316       if (thisShouldBeIgnored(xid.module) && (xid.severity < ELsevere) /* change log 2 */)
0317         return false;
0318       if (!limits.add(xid) && (xid.severity < ELsevere) /* change log 2 */)
0319         return false;
0320
0321 #ifdef ELoutputTRACE_LOG
0322       std::cerr << "    =:=:=: Limits table work done \n";
0323 #endif
0324
0325       // Output the prologue:
0326       //
0327       preambleMode = true;
0328
0329       if (!msg.is_verbatim()) {
0330         charsOnLine = 0;  // Change log 5
0331         emitToken(preamble);
0332         emitToken(xid.severity.getSymbol());
0333         emitToken(" ");
0334         emitToken(xid.id);
0335         emitToken(msg.idOverflow());
0336         emitToken(": ");
0337       }
0338
0339 #ifdef ELoutputTRACE_LOG
0340       std::cerr << "    =:=:=: Prologue done \n";
0341 #endif
0342       // Output serial number of message:
0343       //
0344       if (!msg.is_verbatim()) {
0345         if (wantSerial) {
0346           std::ostringstream s;
0347           s << msg.serial();
0348           emitToken("[serial #" + s.str() + "] ");
0349         }
0350       }
0351
0352 #ifdef OUTPUT_FORMATTED_ERROR_MESSAGES
0353       // Output each item in the message (before the epilogue):
0354       //
0355       if (wantText) {
0356         ELlist_string::const_iterator it;
0357         for (it = msg.items().begin(); it != msg.items().end(); ++it) {
0358 #ifdef ELoutputTRACE_LOG
0359           std::cerr << "      =:=:=: Item:  " << *it << '\n';
0360 #endif
0361           emitToken(*it);
0362         }
0363       }
0364 #endif
0365
0366       // Provide further identification:
0367       //
0368       bool needAspace = true;
0369       if (!msg.is_verbatim()) {
0370         if (wantEpilogueSeparate) {
0371           if (xid.module.length() + xid.subroutine.length() > 0) {
0372             emitToken("\n");
0373             needAspace = false;
0374           } else if (wantTimestamp && !wantTimeSeparate) {
0375             emitToken("\n");
0376             needAspace = false;
0377           }
0378         }
0379         if (wantModule && (!xid.module.empty())) {
0380           if (needAspace) {
0381             emitToken(" ");
0382             needAspace = false;
0383           }
0384           emitToken(xid.module + " ");
0385         }
0386         if (wantSubroutine && (!xid.subroutine.empty())) {
0387           if (needAspace) {
0388             emitToken(" ");
0389             needAspace = false;
0390           }
0391           emitToken(xid.subroutine + "() ");
0392         }
0393       }
0394
0395 #ifdef ELoutputTRACE_LOG
0396       std::cerr << "    =:=:=: Module and Subroutine done \n";
0397 #endif
0398
0399       // Provide time stamp:
0400       //
0401       if (!msg.is_verbatim()) {
0402         if (wantTimestamp) {
0403           if (wantTimeSeparate) {
0404             emitToken("\n");
0405             needAspace = false;
0406           }
0407           if (needAspace) {
0408             emitToken(" ");
0409             needAspace = false;
0410           }
0411           std::string const& ftime = formatTime(msg.timestamp());  // Change log 7
0412           emitToken(ftime + " ");
0413         }
0414       }
0415
0416 #ifdef ELoutputTRACE_LOG
0417       std::cerr << "    =:=:=: TimeStamp done \n";
0418 #endif
0419
0420       // Provide the context information:
0421       //
0422       if (!msg.is_verbatim()) {
0423         if (wantSomeContext) {
0424           if (needAspace) {
0425             emitToken(" ");
0426             needAspace = false;
0427           }
0428           assert(!needAspace);
0429           if (wantFullContext) {
0430             emitToken(msg.context());
0431 #ifdef ELoutputTRACE_LOG
0432             std::cerr << "    =:=:=: fullContext done: \n";
0433 #endif
0434           } else {
0435             emitToken(msg.context());
0436 #ifdef ELoutputTRACE_LOG
0437             std::cerr << "    =:=:=: Context done: \n";
0438 #endif
0439           }
0440         }
0441       }
0442
0443       // Provide traceback information:
0444       //
0445
0446       bool insertNewlineAfterHeader = (msg.xid().severity != ELdebug);
0447       // ELdebug is what LogDebug issues
0448
0449       if (!msg.is_verbatim()) {
0450         if (msg.xid().severity >= traceThreshold) {
0451           emitToken("\n", insertNewlineAfterHeader);
0452         } else {  //else statement added JV:1
0453           emitToken("", insertNewlineAfterHeader);
0454         }
0455       }
0456 #ifdef ELoutputTRACE_LOG
0457       std::cerr << "    =:=:=: Trace routine done: \n";
0458 #endif
0459
0460 #ifndef OUTPUT_FORMATTED_ERROR_MESSAGES
0461       // Finally, output each item in the message:
0462       //
0463       preambleMode = false;
0464       if (wantText) {
0465         ELlist_string::const_iterator it;
0466         int item_count = 0;
0467         for (it = msg.items().begin(); it != msg.items().end(); ++it) {
0468 #ifdef ELoutputTRACE_LOG
0469           std::cerr << "      =:=:=: Item:  " << *it << '\n';
0470 #endif
0471           ++item_count;
0472           if (!msg.is_verbatim()) {
0473             if (!insertNewlineAfterHeader && (item_count == 3)) {
0474               // in a LogDebug message, the first 3 items are FILE, :, and LINE
0475               emitToken(*it, true);
0476             } else {
0477               emitToken(*it);
0478             }
0479           } else {
0480             emitToken(*it);
0481           }
0482         }
0483       }
0484 #endif
0485
0486       // And after the message, add a %MSG on its own line
0487       // Change log 4  6/11/07 mf
0488
0489       if (!msg.is_verbatim()) {
0490         emitToken("\n%MSG");
0491       }
0492
0493       // Done; message has been fully processed; separate, flush, and leave
0494       //
0495
0496       (*os) << newline;
0497       flush();
0498
0499 #ifdef ELoutputTRACE_LOG
0500       std::cerr << "  =:=:=: log(msg) done: \n";
0501 #endif
0502
0503       return true;
0504
0505     }  // log()
0506
0507     // Remainder are from base class.
0508
0509     // ----------------------------------------------------------------------
0510     // Output methods:
0511     // ----------------------------------------------------------------------
0512
0513     void ELoutput::emitToken(std::string_view s, bool nl) {
0514 #ifdef ELoutput_EMIT_TRACE
0515       std::cerr << "[][][] in emit:  charsOnLine is " << charsOnLine << '\n';
0516       std::cerr << "[][][] in emit:  s.length() " << s.length() << '\n';
0517       std::cerr << "[][][] in emit:  lineLength is " << lineLength << '\n';
0518 #endif
0519
0520       if (s.empty()) {
0521         if (nl) {
0522           (*os) << newline << std::flush;
0523           charsOnLine = 0;
0524         }
0525         return;
0526       }
0527
0528       char first = s[0];
0529       char second, last, last2;
0530       second = (s.length() < 2) ? '\0' : s[1];
0531       last = (s.length() < 2) ? '\0' : s[s.length() - 1];
0532       last2 = (s.length() < 3) ? '\0' : s[s.length() - 2];
0533       //checking -2 because the very last char is sometimes a ' ' inserted
0534       //by ErrorLog::operator<<
0535
0536       if (preambleMode) {
0537         //Accounts for newline @ the beginning of the ELstring     JV:2
0538         if (first == '\n' || (charsOnLine + static_cast<int>(s.length())) > lineLength) {
0539 #ifdef ELoutput_EMIT_TRACE
0540           std::cerr << "[][][] in emit: about to << to *os \n";
0541 #endif
0542 #ifdef HEADERS_BROKEN_INTO_LINES_AND_INDENTED
0543           // Change log 3: Removed this code 6/11/07 mf
0544           (*os) << newline << indent;
0545           charsOnLine = indent.length();
0546 #else
0547           charsOnLine = 0;  // Change log 5
0548 #endif
0549           if (second != ' ') {
0550             (*os) << ' ';
0551             charsOnLine++;
0552           }
0553           if (first == '\n') {
0554             (*os) << s.substr(1);
0555           } else {
0556             (*os) << s;
0557           }
0558         }
0559 #ifdef ELoutput_EMIT_TRACE
0560         std::cerr << "[][][] in emit: about to << s to *os: " << s << " \n";
0561 #endif
0562         else {
0563           (*os) << s;
0564         }
0565
0566         if (last == '\n' || last2 == '\n') {  //accounts for newline @ end    $$ JV:2
0567           (*os) << indent;                    //of the ELstring
0568           if (last != ' ')
0569             (*os) << ' ';
0570           charsOnLine = indent.length() + 1;
0571         }
0572
0573         if (nl) {
0574           (*os) << newline << std::flush;
0575           charsOnLine = 0;
0576         } else {
0577           charsOnLine += s.length();
0578         }
0579       }
0580
0581       if (!preambleMode) {
0582         (*os) << s;
0583       }
0584
0585 #ifdef ELoutput_EMIT_TRACE
0586       std::cerr << "[][][] in emit: completed \n";
0587 #endif
0588
0589     }  // emitToken()
0590
0591     // ----------------------------------------------------------------------
0592     // Methods controlling message formatting:
0593     // ----------------------------------------------------------------------
0594
0595     void ELoutput::includeTime() { wantTimestamp = true; }
0596     void ELoutput::suppressTime() { wantTimestamp = false; }
0597
0598     void ELoutput::includeModule() { wantModule = true; }
0599     void ELoutput::suppressModule() { wantModule = false; }
0600
0601     void ELoutput::includeSubroutine() { wantSubroutine = true; }
0602     void ELoutput::suppressSubroutine() { wantSubroutine = false; }
0603
0604     void ELoutput::includeText() { wantText = true; }
0605     void ELoutput::suppressText() { wantText = false; }
0606
0607     void ELoutput::includeContext() { wantSomeContext = true; }
0608     void ELoutput::suppressContext() { wantSomeContext = false; }
0609
0610     void ELoutput::suppressSerial() { wantSerial = false; }
0611     void ELoutput::includeSerial() { wantSerial = true; }
0612
0613     void ELoutput::useFullContext() { wantFullContext = true; }
0614     void ELoutput::useContext() { wantFullContext = false; }
0615
0616     void ELoutput::separateTime() { wantTimeSeparate = true; }
0617     void ELoutput::attachTime() { wantTimeSeparate = false; }
0618
0619     void ELoutput::separateEpilogue() { wantEpilogueSeparate = true; }
0620     void ELoutput::attachEpilogue() { wantEpilogueSeparate = false; }
0621
0622     // ----------------------------------------------------------------------
0623     // Changing ostream:
0624     // ----------------------------------------------------------------------
0625
0626     void ELoutput::changeFile(std::ostream& os_) {
0627       os.reset(&os_, do_nothing_deleter());
0628       emitToken("\n=======================================================", true);
0629       emitToken("\nError Log changed to this stream\n");
0630       std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0631       emitToken(ftime, true);
0632       emitToken("\n=======================================================\n", true);
0633     }
0634
0635     void ELoutput::changeFile(const std::string& filename) {
0636       os.reset(new std::ofstream(filename.c_str(), std::ios /*_base*/ ::app), close_and_delete());  //NOLINT
0637       emitToken("\n=======================================================", true);
0638       emitToken("\nError Log changed to this file\n");
0639       std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0640       emitToken(ftime, true);
0641       emitToken("\n=======================================================\n", true);
0642     }
0643
0644     void ELoutput::flush() { os->flush(); }
0645
0646     // ----------------------------------------------------------------------
0647
0648   }  // end of namespace service
0649 }  // end of namespace edm