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 <iostream>
0087 #include <fstream>
0088 #include <cstring>
0089 #include <cassert>
0090
0091 namespace {
0092   // ----------------------------------------------------------------------
0093   // Useful function:
0094   // ----------------------------------------------------------------------
0095
0096   std::string formatTime(const time_t t) {  // Change log 7
0097
0098     constexpr char dummy[] = "dd-Mon-yyyy hh:mm:ss TZN     ";  // Change log 7 for length only
0099     char ts[sizeof(dummy)];                                    // Change log 7
0100
0101     struct tm timebuf;  // Change log 7
0102
0103     strftime(ts, sizeof(dummy), "%d-%b-%Y %H:%M:%S %Z", localtime_r(&t, &timebuf));  // Change log 7
0104                                                                                      // mf 4-9-04
0105
0106 #ifdef STRIP_TRAILING_BLANKS_IN_TIMEZONE
0107     // strip trailing blanks that would come when the time zone is not as
0108     // long as the maximum allowed - probably not worth the time
0109     unsigned int b = strlen(ts);
0110     while (ts[--b] == ' ') {
0111       ts[b] = 0;
0112     }
0113 #endif
0114
0115     return std::string(ts);  // Change log 7
0116   }                          // formatTime()
0117 }  // namespace
0118
0119 using namespace edm::messagelogger;
0120 namespace edm {
0121   namespace service {
0122     // ----------------------------------------------------------------------
0123     // Constructors:
0124     // ----------------------------------------------------------------------
0125
0126     ELoutput::ELoutput()
0127         : ELdestination(),
0128           os(&std::cerr, do_nothing_deleter()),
0129           charsOnLine(0),
0130           xid(),
0131           wantTimestamp(true),
0132           wantModule(true),
0133           wantSubroutine(true),
0134           wantText(true),
0135           wantSomeContext(true),
0136           wantSerial(false),
0137           wantFullContext(false),
0138           wantTimeSeparate(false),
0139           wantEpilogueSeparate(false),
0140           preambleMode(true)  // 006 9/2/10 mf
0141     {
0142 #ifdef ELoutputCONSTRUCTOR_TRACE
0143       std::cerr << "Constructor for ELoutput()\n";
0144 #endif
0145
0146       emitToken("\n=================================================", true);
0147       emitToken("\nMessage Log File written by MessageLogger service \n");
0148       emitToken("\n=================================================\n", true);
0149
0150     }  // ELoutput()
0151
0152     ELoutput::ELoutput(std::ostream& os_, bool emitAtStart)
0153         : ELdestination(),
0154           os(&os_, do_nothing_deleter()),
0155           charsOnLine(0),
0156           xid(),
0157           wantTimestamp(true),
0158           wantModule(true),
0159           wantSubroutine(true),
0160           wantText(true),
0161           wantSomeContext(true),
0162           wantSerial(false),
0163           wantFullContext(false),
0164           wantTimeSeparate(false),
0165           wantEpilogueSeparate(false),
0166           preambleMode(true)  // 006 9/2/10 mf
0167     {
0168 #ifdef ELoutputCONSTRUCTOR_TRACE
0169       std::cerr << "Constructor for ELoutput( os )\n";
0170 #endif
0171
0172       // Enh 001 2/13/01 mf
0173       if (emitAtStart) {
0174         preambleMode = true;
0175         emitToken("\n=================================================", true);
0176         emitToken("\nMessage Log File written by MessageLogger service \n");
0177         emitToken("\n=================================================\n", true);
0178       }
0179
0180     }  // ELoutput()
0181
0182     ELoutput::ELoutput(const std::string& fileName, bool emitAtStart)
0183         : ELdestination(),
0184           os(new std::ofstream(fileName.c_str(), std::ios /*_base*/ ::app), close_and_delete()),
0185           charsOnLine(0),
0186           xid(),
0187           wantTimestamp(true),
0188           wantModule(true),
0189           wantSubroutine(true),
0190           wantText(true),
0191           wantSomeContext(true),
0192           wantSerial(false),
0193           wantFullContext(false),
0194           wantTimeSeparate(false),
0195           wantEpilogueSeparate(false),
0196           preambleMode(true)  // 006 9/2/10 mf
0197     {
0198 #ifdef ELoutputCONSTRUCTOR_TRACE
0199       std::cerr << "Constructor for ELoutput( " << fileName << " )\n";
0200 #endif
0201
0202       preambleMode = true;
0203       if (os && *os) {
0204 #ifdef ELoutputCONSTRUCTOR_TRACE
0205         std::cerr << "          Testing if os is owned\n";
0206 #endif
0207 #ifdef ELoutputCONSTRUCTOR_TRACE
0208         std::cerr << "          About to do first emit\n";
0209 #endif
0210         // Enh 001 2/13/01 mf
0211         if (emitAtStart) {
0212           emitToken("\n=======================================================", true);
0213           emitToken("\nError Log File ");
0214           emitToken(fileName);
0215           emitToken(" \n");
0216         }
0217       } else {
0218 #ifdef ELoutputCONSTRUCTOR_TRACE
0219         std::cerr << "          Deleting os\n";
0220 #endif
0221         os.reset(&std::cerr, do_nothing_deleter());
0222 #ifdef ELoutputCONSTRUCTOR_TRACE
0223         std::cerr << "          about to emit to cerr\n";
0224 #endif
0225         if (emitAtStart) {
0226           emitToken("\n=======================================================", true);
0227           emitToken("\n%MSG** Logging to cerr is being substituted");
0228           emitToken(" for specified log file \"");
0229           emitToken(fileName);
0230           emitToken("\" which could not be opened for write or append.\n");
0231         }
0232       }
0233       if (emitAtStart) {
0234         std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0235         emitToken(ftime, true);
0236         emitToken("\n=======================================================\n", true);
0237       }
0238       // preambleMode = tprm; removed 9/2/10 mf see change log 6
0239
0240 #ifdef ELoutputCONSTRUCTOR_TRACE
0241       std::cerr << "Constructor for ELoutput completed.\n";
0242 #endif
0243
0244     }  // ELoutput()
0245
0246     ELoutput::ELoutput(const ELoutput& orig)
0247         : ELdestination(),
0248           os(orig.os),
0249           charsOnLine(orig.charsOnLine),
0250           xid(orig.xid),
0251           wantTimestamp(orig.wantTimestamp),
0252           wantModule(orig.wantModule),
0253           wantSubroutine(orig.wantSubroutine),
0254           wantText(orig.wantText),
0255           wantSomeContext(orig.wantSomeContext),
0256           wantSerial(orig.wantSerial),
0257           wantFullContext(orig.wantFullContext),
0258           wantTimeSeparate(orig.wantTimeSeparate),
0259           wantEpilogueSeparate(orig.wantEpilogueSeparate),
0260           preambleMode(orig.preambleMode)  // 006 9/2/10 mf
0261     {
0262 #ifdef ELoutputCONSTRUCTOR_TRACE
0263       std::cerr << "Copy constructor for ELoutput\n";
0264 #endif
0265
0266       // mf 6/15/01 fix of Bug 005
0267       threshold = orig.threshold;
0268       traceThreshold = orig.traceThreshold;
0269       limits = orig.limits;
0270       preamble = orig.preamble;
0271       newline = orig.newline;
0272       indent = orig.indent;
0273       lineLength = orig.lineLength;
0274
0275       ignoreMostModules = orig.ignoreMostModules;
0276       respondToThese = orig.respondToThese;
0277       respondToMostModules = orig.respondToMostModules;
0278       ignoreThese = orig.ignoreThese;
0279
0280     }  // ELoutput()
0281
0282     ELoutput::~ELoutput() {
0283 #ifdef ELoutputCONSTRUCTOR_TRACE
0284       std::cerr << "Destructor for ELoutput\n";
0285 #endif
0286
0287     }  // ~ELoutput()
0288
0289     // ----------------------------------------------------------------------
0290     // Methods invoked by the ELadministrator:
0291     // ----------------------------------------------------------------------
0292
0293     //#define THRESHTRACE
0294     //#define ELoutputTRACE_LOG
0295
0296     bool ELoutput::log(const edm::ErrorObj& msg) {
0297 #ifdef ELoutputTRACE_LOG
0298       std::cerr << "    =:=:=: Log to an ELoutput \n";
0299 #endif
0300
0301       xid = msg.xid();  // Save the xid.
0302
0303 #ifdef THRESHTRACE
0304       std::cerr << "    =:=:=: Log to an ELoutput \n"
0305                 << "           severity  = " << xid.severity << "\n"
0306                 << "           threshold = " << threshold << "\n"
0307                 << "           id        = " << xid.id << "\n";
0308 #endif
0309
0310       // See if this message is to be acted upon, and add it to limits table
0311       // if it was not already present:
0312       //
0313       if (xid.severity < threshold)
0314         return false;
0315       if (thisShouldBeIgnored(xid.module) && (xid.severity < ELsevere) /* change log 2 */)
0316         return false;
0317       if (!limits.add(xid) && (xid.severity < ELsevere) /* change log 2 */)
0318         return false;
0319
0320 #ifdef ELoutputTRACE_LOG
0321       std::cerr << "    =:=:=: Limits table work done \n";
0322 #endif
0323
0324       // Output the prologue:
0325       //
0326       preambleMode = true;
0327
0328       if (!msg.is_verbatim()) {
0329         charsOnLine = 0;  // Change log 5
0330         emitToken(preamble);
0331         emitToken(xid.severity.getSymbol());
0332         emitToken(" ");
0333         emitToken(xid.id);
0334         emitToken(msg.idOverflow());
0335         emitToken(": ");
0336       }
0337
0338 #ifdef ELoutputTRACE_LOG
0339       std::cerr << "    =:=:=: Prologue done \n";
0340 #endif
0341       // Output serial number of message:
0342       //
0343       if (!msg.is_verbatim()) {
0344         if (wantSerial) {
0345           std::ostringstream s;
0346           s << msg.serial();
0347           emitToken("[serial #" + s.str() + "] ");
0348         }
0349       }
0350
0351 #ifdef OUTPUT_FORMATTED_ERROR_MESSAGES
0352       // Output each item in the message (before the epilogue):
0353       //
0354       if (wantText) {
0355         ELlist_string::const_iterator it;
0356         for (it = msg.items().begin(); it != msg.items().end(); ++it) {
0357 #ifdef ELoutputTRACE_LOG
0358           std::cerr << "      =:=:=: Item:  " << *it << '\n';
0359 #endif
0360           emitToken(*it);
0361         }
0362       }
0363 #endif
0364
0365       // Provide further identification:
0366       //
0367       bool needAspace = true;
0368       if (!msg.is_verbatim()) {
0369         if (wantEpilogueSeparate) {
0370           if (xid.module.length() + xid.subroutine.length() > 0) {
0371             emitToken("\n");
0372             needAspace = false;
0373           } else if (wantTimestamp && !wantTimeSeparate) {
0374             emitToken("\n");
0375             needAspace = false;
0376           }
0377         }
0378         if (wantModule && (xid.module.length() > 0)) {
0379           if (needAspace) {
0380             emitToken(" ");
0381             needAspace = false;
0382           }
0383           emitToken(xid.module + " ");
0384         }
0385         if (wantSubroutine && (xid.subroutine.length() > 0)) {
0386           if (needAspace) {
0387             emitToken(" ");
0388             needAspace = false;
0389           }
0390           emitToken(xid.subroutine + "() ");
0391         }
0392       }
0393
0394 #ifdef ELoutputTRACE_LOG
0395       std::cerr << "    =:=:=: Module and Subroutine done \n";
0396 #endif
0397
0398       // Provide time stamp:
0399       //
0400       if (!msg.is_verbatim()) {
0401         if (wantTimestamp) {
0402           if (wantTimeSeparate) {
0403             emitToken("\n");
0404             needAspace = false;
0405           }
0406           if (needAspace) {
0407             emitToken(" ");
0408             needAspace = false;
0409           }
0410           std::string const& ftime = formatTime(msg.timestamp());  // Change log 7
0411           emitToken(ftime + " ");
0412         }
0413       }
0414
0415 #ifdef ELoutputTRACE_LOG
0416       std::cerr << "    =:=:=: TimeStamp done \n";
0417 #endif
0418
0419       // Provide the context information:
0420       //
0421       if (!msg.is_verbatim()) {
0422         if (wantSomeContext) {
0423           if (needAspace) {
0424             emitToken(" ");
0425             needAspace = false;
0426           }
0427           assert(!needAspace);
0428           if (wantFullContext) {
0429             emitToken(msg.context());
0430 #ifdef ELoutputTRACE_LOG
0431             std::cerr << "    =:=:=: fullContext done: \n";
0432 #endif
0433           } else {
0434             emitToken(msg.context());
0435 #ifdef ELoutputTRACE_LOG
0436             std::cerr << "    =:=:=: Context done: \n";
0437 #endif
0438           }
0439         }
0440       }
0441
0442       // Provide traceback information:
0443       //
0444
0445       bool insertNewlineAfterHeader = (msg.xid().severity != ELdebug);
0446       // ELdebug is what LogDebug issues
0447
0448       if (!msg.is_verbatim()) {
0449         if (msg.xid().severity >= traceThreshold) {
0450           emitToken("\n", insertNewlineAfterHeader);
0451         } else {  //else statement added JV:1
0452           emitToken("", insertNewlineAfterHeader);
0453         }
0454       }
0455 #ifdef ELoutputTRACE_LOG
0456       std::cerr << "    =:=:=: Trace routine done: \n";
0457 #endif
0458
0459 #ifndef OUTPUT_FORMATTED_ERROR_MESSAGES
0460       // Finally, output each item in the message:
0461       //
0462       preambleMode = false;
0463       if (wantText) {
0464         ELlist_string::const_iterator it;
0465         int item_count = 0;
0466         for (it = msg.items().begin(); it != msg.items().end(); ++it) {
0467 #ifdef ELoutputTRACE_LOG
0468           std::cerr << "      =:=:=: Item:  " << *it << '\n';
0469 #endif
0470           ++item_count;
0471           if (!msg.is_verbatim()) {
0472             if (!insertNewlineAfterHeader && (item_count == 3)) {
0473               // in a LogDebug message, the first 3 items are FILE, :, and LINE
0474               emitToken(*it, true);
0475             } else {
0476               emitToken(*it);
0477             }
0478           } else {
0479             emitToken(*it);
0480           }
0481         }
0482       }
0483 #endif
0484
0485       // And after the message, add a %MSG on its own line
0486       // Change log 4  6/11/07 mf
0487
0488       if (!msg.is_verbatim()) {
0489         emitToken("\n%MSG");
0490       }
0491
0492       // Done; message has been fully processed; separate, flush, and leave
0493       //
0494
0495       (*os) << newline;
0496       flush();
0497
0498 #ifdef ELoutputTRACE_LOG
0499       std::cerr << "  =:=:=: log(msg) done: \n";
0500 #endif
0501
0502       return true;
0503
0504     }  // log()
0505
0506     // Remainder are from base class.
0507
0508     // ----------------------------------------------------------------------
0509     // Output methods:
0510     // ----------------------------------------------------------------------
0511
0512     void ELoutput::emitToken(std::string_view s, bool nl) {
0513 #ifdef ELoutput_EMIT_TRACE
0514       std::cerr << "[][][] in emit:  charsOnLine is " << charsOnLine << '\n';
0515       std::cerr << "[][][] in emit:  s.length() " << s.length() << '\n';
0516       std::cerr << "[][][] in emit:  lineLength is " << lineLength << '\n';
0517 #endif
0518
0519       if (s.length() == 0) {
0520         if (nl) {
0521           (*os) << newline << std::flush;
0522           charsOnLine = 0;
0523         }
0524         return;
0525       }
0526
0527       char first = s[0];
0528       char second, last, last2;
0529       second = (s.length() < 2) ? '\0' : s[1];
0530       last = (s.length() < 2) ? '\0' : s[s.length() - 1];
0531       last2 = (s.length() < 3) ? '\0' : s[s.length() - 2];
0532       //checking -2 because the very last char is sometimes a ' ' inserted
0533       //by ErrorLog::operator<<
0534
0535       if (preambleMode) {
0536         //Accounts for newline @ the beginning of the ELstring     JV:2
0537         if (first == '\n' || (charsOnLine + static_cast<int>(s.length())) > lineLength) {
0538 #ifdef ELoutput_EMIT_TRACE
0539           std::cerr << "[][][] in emit: about to << to *os \n";
0540 #endif
0541 #ifdef HEADERS_BROKEN_INTO_LINES_AND_INDENTED
0542           // Change log 3: Removed this code 6/11/07 mf
0543           (*os) << newline << indent;
0544           charsOnLine = indent.length();
0545 #else
0546           charsOnLine = 0;  // Change log 5
0547 #endif
0548           if (second != ' ') {
0549             (*os) << ' ';
0550             charsOnLine++;
0551           }
0552           if (first == '\n') {
0553             (*os) << s.substr(1);
0554           } else {
0555             (*os) << s;
0556           }
0557         }
0558 #ifdef ELoutput_EMIT_TRACE
0559         std::cerr << "[][][] in emit: about to << s to *os: " << s << " \n";
0560 #endif
0561         else {
0562           (*os) << s;
0563         }
0564
0565         if (last == '\n' || last2 == '\n') {  //accounts for newline @ end    $$ JV:2
0566           (*os) << indent;                    //of the ELstring
0567           if (last != ' ')
0568             (*os) << ' ';
0569           charsOnLine = indent.length() + 1;
0570         }
0571
0572         if (nl) {
0573           (*os) << newline << std::flush;
0574           charsOnLine = 0;
0575         } else {
0576           charsOnLine += s.length();
0577         }
0578       }
0579
0580       if (!preambleMode) {
0581         (*os) << s;
0582       }
0583
0584 #ifdef ELoutput_EMIT_TRACE
0585       std::cerr << "[][][] in emit: completed \n";
0586 #endif
0587
0588     }  // emitToken()
0589
0590     // ----------------------------------------------------------------------
0591     // Methods controlling message formatting:
0592     // ----------------------------------------------------------------------
0593
0594     void ELoutput::includeTime() { wantTimestamp = true; }
0595     void ELoutput::suppressTime() { wantTimestamp = false; }
0596
0597     void ELoutput::includeModule() { wantModule = true; }
0598     void ELoutput::suppressModule() { wantModule = false; }
0599
0600     void ELoutput::includeSubroutine() { wantSubroutine = true; }
0601     void ELoutput::suppressSubroutine() { wantSubroutine = false; }
0602
0603     void ELoutput::includeText() { wantText = true; }
0604     void ELoutput::suppressText() { wantText = false; }
0605
0606     void ELoutput::includeContext() { wantSomeContext = true; }
0607     void ELoutput::suppressContext() { wantSomeContext = false; }
0608
0609     void ELoutput::suppressSerial() { wantSerial = false; }
0610     void ELoutput::includeSerial() { wantSerial = true; }
0611
0612     void ELoutput::useFullContext() { wantFullContext = true; }
0613     void ELoutput::useContext() { wantFullContext = false; }
0614
0615     void ELoutput::separateTime() { wantTimeSeparate = true; }
0616     void ELoutput::attachTime() { wantTimeSeparate = false; }
0617
0618     void ELoutput::separateEpilogue() { wantEpilogueSeparate = true; }
0619     void ELoutput::attachEpilogue() { wantEpilogueSeparate = false; }
0620
0621     // ----------------------------------------------------------------------
0622     // Changing ostream:
0623     // ----------------------------------------------------------------------
0624
0625     void ELoutput::changeFile(std::ostream& os_) {
0626       os.reset(&os_, do_nothing_deleter());
0627       emitToken("\n=======================================================", true);
0628       emitToken("\nError Log changed to this stream\n");
0629       std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0630       emitToken(ftime, true);
0631       emitToken("\n=======================================================\n", true);
0632     }
0633
0634     void ELoutput::changeFile(const std::string& filename) {
0635       os.reset(new std::ofstream(filename.c_str(), std::ios /*_base*/ ::app), close_and_delete());
0636       emitToken("\n=======================================================", true);
0637       emitToken("\nError Log changed to this file\n");
0638       std::string const& ftime = formatTime(time(nullptr));  // Change log 7
0639       emitToken(ftime, true);
0640       emitToken("\n=======================================================\n", true);
0641     }
0642
0643     void ELoutput::flush() { os->flush(); }
0644
0645     // ----------------------------------------------------------------------
0646
0647   }  // end of namespace service
0648 }  // end of namespace edm