ELoutput.cc

Go to the documentation of this file.

// ----------------------------------------------------------------------
//
// ELoutput.cc
//
//
// 7/8/98       mf      Created
// 6/10/99      jv      JV:1 puts a \n after each log using suppressContext()
// 6/11/99      jv      JV:2 accounts for newline at the beginning and end of
//                           an emitted ELstring
// 6/14/99      mf      Made the static char* in formatTime into auto so that
//                      ctime(&t) is called each time - corrects the bug of
//                      never changing the first timestamp.
// 6/15/99      mf      Inserted operator<<(void (*f)(ErrorLog&) to avoid
//                      mystery characters being inserted when users <<
//                      endmsg to an ErrorObj.
// 7/2/99       jv      Added separate/attachTime, Epilogue, and Serial options
// 8/2/99       jv      Modified handling of newline in an emmitted ELstring
// 2/22/00      mf      Changed usage of myDestX to myOutputX.  Added
//                      constructor of ELoutput from ELoutputX * to allow for
//                      inheritance.
// 6/7/00       web     Reflect consolidation of ELdestination/X; consolidate
//                      ELoutput/X; add filterModule() and query logic
// 10/4/00      mf      excludeModule()
// 1/15/01      mf      line length control: changed ELoutputLineLen to
//                      the base class lineLen (no longer static const)
// 2/13/01      mf      Added emitAtStart argument to two constructors
//                      { Enh 001 }.
// 4/4/01       mf      Simplify filter/exclude logic by useing base class
//                      method thisShouldBeIgnored().  Eliminate
//                      moduleOfinterest and moduleToexclude.
// 6/15/01      mf      Repaired Bug 005 by explicitly setting all
//                      ELdestination member data appropriately.
//10/18/01      mf      When epilogue not on separate line, preceed by space
// 6/23/03      mf      changeFile(), flush()
// 4/09/04      mf      Add 1 to length in strftime call in formatTime, to
//                      correctly provide the time zone.  Had been providing
//                      CST every time.
//
// 12/xx/06     mf  Tailoring to CMS MessageLogger
//  1/11/06 mf      Eliminate time stamp from starting message
//  3/20/06 mf  Major formatting change to do no formatting
//          except the header and line separation.
//  4/04/06 mf  Move the line feed between header and text
//          till after the first 3 items (FILE:LINE) for
//          debug messages.
//  6/06/06 mf  Verbatim
//  6/12/06 mf  Set preambleMode true when printing the header
//
// Change Log
//
//  1 10/18/06  mf  In format_time(): Initialized ts[] with 5 extra
//          spaces, to cover cases where time zone is more than
//          3 characters long
//
//  2 10/30/06  mf  In log():  if severity indicated is SEVERE, do not
//          impose limits.  This is to implement the LogSystem
//          feature:  Those messages are never to be ignored.
//
//  3 6/11/07  mf   In emitToken():  In preamble mode, do not break and indent
//          even if exceeding nominal line length.
//
//  4 6/11/07  mf   In log():  After the message, add a %MSG on its own line
//
//  5 3/27/09  mf   Properly treat charsOnLine, which had been fouled due to
//          change 3.  In log() and emitToken().
//
//  6 9/2/10  mf    Initialize preambleMode in each ctor, and remove the
//          unnecessary use of tprm which was preserving a moot
//          initial value.
//
//  7 9/30/10 wmtan make formatTime() thread safe by not using statics.
//
// ----------------------------------------------------------------------

#include "FWCore/MessageService/src/ELoutput.h"

#include "FWCore/MessageLogger/interface/ErrorObj.h"

#include "FWCore/Utilities/interface/do_nothing_deleter.h"

// Possible Traces:
// #define ELoutputCONSTRUCTOR_TRACE
// #define ELoutputTRACE_LOG
// #define ELoutput_EMIT_TRACE

#include <iostream>
#include <fstream>
#include <cstring>
#include <cassert>

namespace {
  // ----------------------------------------------------------------------
  // Useful function:
  // ----------------------------------------------------------------------

  std::string formatTime(const time_t t) {  // Change log 7

    constexpr char dummy[] = "dd-Mon-yyyy hh:mm:ss TZN     ";  // Change log 7 for length only
    char ts[sizeof(dummy)];                                    // Change log 7

    struct tm timebuf;  // Change log 7

    strftime(ts, sizeof(dummy), "%d-%b-%Y %H:%M:%S %Z", localtime_r(&t, &timebuf));  // Change log 7
                                                                                     // mf 4-9-04

#ifdef STRIP_TRAILING_BLANKS_IN_TIMEZONE
    // strip trailing blanks that would come when the time zone is not as
    // long as the maximum allowed - probably not worth the time
    unsigned int b = strlen(ts);
    while (ts[--b] == ' ') {
      ts[b] = 0;
    }
#endif

    return std::string(ts);  // Change log 7
  }                          // formatTime()
}  // namespace

using namespace edm::messagelogger;
namespace edm {
  namespace service {
    // ----------------------------------------------------------------------
    // Constructors:
    // ----------------------------------------------------------------------

    ELoutput::ELoutput()
        : ELdestination(),
          os(&std::cerr, do_nothing_deleter()),
          charsOnLine(0),
          xid(),
          wantTimestamp(true),
          wantModule(true),
          wantSubroutine(true),
          wantText(true),
          wantSomeContext(true),
          wantSerial(false),
          wantFullContext(false),
          wantTimeSeparate(false),
          wantEpilogueSeparate(false),
          preambleMode(true)  // 006 9/2/10 mf
    {
#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Constructor for ELoutput()\n";
#endif

      emitToken("\n=================================================", true);
      emitToken("\nMessage Log File written by MessageLogger service \n");
      emitToken("\n=================================================\n", true);

    }  // ELoutput()

    ELoutput::ELoutput(std::ostream& os_, bool emitAtStart)
        : ELdestination(),
          os(&os_, do_nothing_deleter()),
          charsOnLine(0),
          xid(),
          wantTimestamp(true),
          wantModule(true),
          wantSubroutine(true),
          wantText(true),
          wantSomeContext(true),
          wantSerial(false),
          wantFullContext(false),
          wantTimeSeparate(false),
          wantEpilogueSeparate(false),
          preambleMode(true)  // 006 9/2/10 mf
    {
#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Constructor for ELoutput( os )\n";
#endif

      // Enh 001 2/13/01 mf
      if (emitAtStart) {
        preambleMode = true;
        emitToken("\n=================================================", true);
        emitToken("\nMessage Log File written by MessageLogger service \n");
        emitToken("\n=================================================\n", true);
      }

    }  // ELoutput()

    ELoutput::ELoutput(const std::string& fileName, bool emitAtStart)
        : ELdestination(),
          os(new std::ofstream(fileName.c_str(), std::ios /*_base*/ ::app), close_and_delete()),
          charsOnLine(0),
          xid(),
          wantTimestamp(true),
          wantModule(true),
          wantSubroutine(true),
          wantText(true),
          wantSomeContext(true),
          wantSerial(false),
          wantFullContext(false),
          wantTimeSeparate(false),
          wantEpilogueSeparate(false),
          preambleMode(true)  // 006 9/2/10 mf
    {
#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Constructor for ELoutput( " << fileName << " )\n";
#endif

      preambleMode = true;
      if (os && *os) {
#ifdef ELoutputCONSTRUCTOR_TRACE
        std::cerr << "          Testing if os is owned\n";
#endif
#ifdef ELoutputCONSTRUCTOR_TRACE
        std::cerr << "          About to do first emit\n";
#endif
        // Enh 001 2/13/01 mf
        if (emitAtStart) {
          emitToken("\n=======================================================", true);
          emitToken("\nError Log File ");
          emitToken(fileName);
          emitToken(" \n");
        }
      } else {
#ifdef ELoutputCONSTRUCTOR_TRACE
        std::cerr << "          Deleting os\n";
#endif
        os.reset(&std::cerr, do_nothing_deleter());
#ifdef ELoutputCONSTRUCTOR_TRACE
        std::cerr << "          about to emit to cerr\n";
#endif
        if (emitAtStart) {
          emitToken("\n=======================================================", true);
          emitToken("\n%MSG** Logging to cerr is being substituted");
          emitToken(" for specified log file \"");
          emitToken(fileName);
          emitToken("\" which could not be opened for write or append.\n");
        }
      }
      if (emitAtStart) {
        std::string const& ftime = formatTime(time(nullptr));  // Change log 7
        emitToken(ftime, true);
        emitToken("\n=======================================================\n", true);
      }
      // preambleMode = tprm; removed 9/2/10 mf see change log 6

#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Constructor for ELoutput completed.\n";
#endif

    }  // ELoutput()

    ELoutput::ELoutput(const ELoutput& orig)
        : ELdestination(),
          os(orig.os),
          charsOnLine(orig.charsOnLine),
          xid(orig.xid),
          wantTimestamp(orig.wantTimestamp),
          wantModule(orig.wantModule),
          wantSubroutine(orig.wantSubroutine),
          wantText(orig.wantText),
          wantSomeContext(orig.wantSomeContext),
          wantSerial(orig.wantSerial),
          wantFullContext(orig.wantFullContext),
          wantTimeSeparate(orig.wantTimeSeparate),
          wantEpilogueSeparate(orig.wantEpilogueSeparate),
          preambleMode(orig.preambleMode)  // 006 9/2/10 mf
    {
#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Copy constructor for ELoutput\n";
#endif

      // mf 6/15/01 fix of Bug 005
      threshold = orig.threshold;
      traceThreshold = orig.traceThreshold;
      limits = orig.limits;
      preamble = orig.preamble;
      newline = orig.newline;
      indent = orig.indent;
      lineLength = orig.lineLength;

      ignoreMostModules = orig.ignoreMostModules;
      respondToThese = orig.respondToThese;
      respondToMostModules = orig.respondToMostModules;
      ignoreThese = orig.ignoreThese;

    }  // ELoutput()

    ELoutput::~ELoutput() {
#ifdef ELoutputCONSTRUCTOR_TRACE
      std::cerr << "Destructor for ELoutput\n";
#endif

    }  // ~ELoutput()

    // ----------------------------------------------------------------------
    // Methods invoked by the ELadministrator:
    // ----------------------------------------------------------------------

    //#define THRESHTRACE
    //#define ELoutputTRACE_LOG

    bool ELoutput::log(const edm::ErrorObj& msg) {
#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: Log to an ELoutput \n";
#endif

      xid = msg.xid();  // Save the xid.

#ifdef THRESHTRACE
      std::cerr << "    =:=:=: Log to an ELoutput \n"
                << "           severity  = " << xid.severity << "\n"
                << "           threshold = " << threshold << "\n"
                << "           id        = " << xid.id << "\n";
#endif

      // See if this message is to be acted upon, and add it to limits table
      // if it was not already present:
      //
      if (xid.severity < threshold)
        return false;
      if (thisShouldBeIgnored(xid.module) && (xid.severity < ELsevere) /* change log 2 */)
        return false;
      if (!limits.add(xid) && (xid.severity < ELsevere) /* change log 2 */)
        return false;

#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: Limits table work done \n";
#endif

      // Output the prologue:
      //
      preambleMode = true;

      if (!msg.is_verbatim()) {
        charsOnLine = 0;  // Change log 5
        emitToken(preamble);
        emitToken(xid.severity.getSymbol());
        emitToken(" ");
        emitToken(xid.id);
        emitToken(msg.idOverflow());
        emitToken(": ");
      }

#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: Prologue done \n";
#endif
      // Output serial number of message:
      //
      if (!msg.is_verbatim()) {
        if (wantSerial) {
          std::ostringstream s;
          s << msg.serial();
          emitToken("[serial #" + s.str() + "] ");
        }
      }

#ifdef OUTPUT_FORMATTED_ERROR_MESSAGES
      // Output each item in the message (before the epilogue):
      //
      if (wantText) {
        ELlist_string::const_iterator it;
        for (it = msg.items().begin(); it != msg.items().end(); ++it) {
#ifdef ELoutputTRACE_LOG
          std::cerr << "      =:=:=: Item:  " << *it << '\n';
#endif
          emitToken(*it);
        }
      }
#endif

      // Provide further identification:
      //
      bool needAspace = true;
      if (!msg.is_verbatim()) {
        if (wantEpilogueSeparate) {
          if (xid.module.length() + xid.subroutine.length() > 0) {
            emitToken("\n");
            needAspace = false;
          } else if (wantTimestamp && !wantTimeSeparate) {
            emitToken("\n");
            needAspace = false;
          }
        }
        if (wantModule && (xid.module.length() > 0)) {
          if (needAspace) {
            emitToken(" ");
            needAspace = false;
          }
          emitToken(xid.module + " ");
        }
        if (wantSubroutine && (xid.subroutine.length() > 0)) {
          if (needAspace) {
            emitToken(" ");
            needAspace = false;
          }
          emitToken(xid.subroutine + "() ");
        }
      }

#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: Module and Subroutine done \n";
#endif

      // Provide time stamp:
      //
      if (!msg.is_verbatim()) {
        if (wantTimestamp) {
          if (wantTimeSeparate) {
            emitToken("\n");
            needAspace = false;
          }
          if (needAspace) {
            emitToken(" ");
            needAspace = false;
          }
          std::string const& ftime = formatTime(msg.timestamp());  // Change log 7
          emitToken(ftime + " ");
        }
      }

#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: TimeStamp done \n";
#endif

      // Provide the context information:
      //
      if (!msg.is_verbatim()) {
        if (wantSomeContext) {
          if (needAspace) {
            emitToken(" ");
            needAspace = false;
          }
          assert(!needAspace);
          if (wantFullContext) {
            emitToken(msg.context());
#ifdef ELoutputTRACE_LOG
            std::cerr << "    =:=:=: fullContext done: \n";
#endif
          } else {
            emitToken(msg.context());
#ifdef ELoutputTRACE_LOG
            std::cerr << "    =:=:=: Context done: \n";
#endif
          }
        }
      }

      // Provide traceback information:
      //

      bool insertNewlineAfterHeader = (msg.xid().severity != ELdebug);
      // ELdebug is what LogDebug issues

      if (!msg.is_verbatim()) {
        if (msg.xid().severity >= traceThreshold) {
          emitToken("\n", insertNewlineAfterHeader);
        } else {  //else statement added JV:1
          emitToken("", insertNewlineAfterHeader);
        }
      }
#ifdef ELoutputTRACE_LOG
      std::cerr << "    =:=:=: Trace routine done: \n";
#endif

#ifndef OUTPUT_FORMATTED_ERROR_MESSAGES
      // Finally, output each item in the message:
      //
      preambleMode = false;
      if (wantText) {
        ELlist_string::const_iterator it;
        int item_count = 0;
        for (it = msg.items().begin(); it != msg.items().end(); ++it) {
#ifdef ELoutputTRACE_LOG
          std::cerr << "      =:=:=: Item:  " << *it << '\n';
#endif
          ++item_count;
          if (!msg.is_verbatim()) {
            if (!insertNewlineAfterHeader && (item_count == 3)) {
              // in a LogDebug message, the first 3 items are FILE, :, and LINE
              emitToken(*it, true);
            } else {
              emitToken(*it);
            }
          } else {
            emitToken(*it);
          }
        }
      }
#endif

      // And after the message, add a %MSG on its own line
      // Change log 4  6/11/07 mf

      if (!msg.is_verbatim()) {
        emitToken("\n%MSG");
      }

      // Done; message has been fully processed; separate, flush, and leave
      //

      (*os) << newline;
      flush();

#ifdef ELoutputTRACE_LOG
      std::cerr << "  =:=:=: log(msg) done: \n";
#endif

      return true;

    }  // log()

    // Remainder are from base class.

    // ----------------------------------------------------------------------
    // Output methods:
    // ----------------------------------------------------------------------

    void ELoutput::emitToken(std::string_view s, bool nl) {
#ifdef ELoutput_EMIT_TRACE
      std::cerr << "[][][] in emit:  charsOnLine is " << charsOnLine << '\n';
      std::cerr << "[][][] in emit:  s.length() " << s.length() << '\n';
      std::cerr << "[][][] in emit:  lineLength is " << lineLength << '\n';
#endif

      if (s.length() == 0) {
        if (nl) {
          (*os) << newline << std::flush;
          charsOnLine = 0;
        }
        return;
      }

      char first = s[0];
      char second, last, last2;
      second = (s.length() < 2) ? '\0' : s[1];
      last = (s.length() < 2) ? '\0' : s[s.length() - 1];
      last2 = (s.length() < 3) ? '\0' : s[s.length() - 2];
      //checking -2 because the very last char is sometimes a ' ' inserted
      //by ErrorLog::operator<<

      if (preambleMode) {
        //Accounts for newline @ the beginning of the ELstring     JV:2
        if (first == '\n' || (charsOnLine + static_cast<int>(s.length())) > lineLength) {
#ifdef ELoutput_EMIT_TRACE
          std::cerr << "[][][] in emit: about to << to *os \n";
#endif
#ifdef HEADERS_BROKEN_INTO_LINES_AND_INDENTED
          // Change log 3: Removed this code 6/11/07 mf
          (*os) << newline << indent;
          charsOnLine = indent.length();
#else
          charsOnLine = 0;  // Change log 5
#endif
          if (second != ' ') {
            (*os) << ' ';
            charsOnLine++;
          }
          if (first == '\n') {
            (*os) << s.substr(1);
          } else {
            (*os) << s;
          }
        }
#ifdef ELoutput_EMIT_TRACE
        std::cerr << "[][][] in emit: about to << s to *os: " << s << " \n";
#endif
        else {
          (*os) << s;
        }

        if (last == '\n' || last2 == '\n') {  //accounts for newline @ end    $$ JV:2
          (*os) << indent;                    //of the ELstring
          if (last != ' ')
            (*os) << ' ';
          charsOnLine = indent.length() + 1;
        }

        if (nl) {
          (*os) << newline << std::flush;
          charsOnLine = 0;
        } else {
          charsOnLine += s.length();
        }
      }

      if (!preambleMode) {
        (*os) << s;
      }

#ifdef ELoutput_EMIT_TRACE
      std::cerr << "[][][] in emit: completed \n";
#endif

    }  // emitToken()

    // ----------------------------------------------------------------------
    // Methods controlling message formatting:
    // ----------------------------------------------------------------------

    void ELoutput::includeTime() { wantTimestamp = true; }
    void ELoutput::suppressTime() { wantTimestamp = false; }

    void ELoutput::includeModule() { wantModule = true; }
    void ELoutput::suppressModule() { wantModule = false; }

    void ELoutput::includeSubroutine() { wantSubroutine = true; }
    void ELoutput::suppressSubroutine() { wantSubroutine = false; }

    void ELoutput::includeText() { wantText = true; }
    void ELoutput::suppressText() { wantText = false; }

    void ELoutput::includeContext() { wantSomeContext = true; }
    void ELoutput::suppressContext() { wantSomeContext = false; }

    void ELoutput::suppressSerial() { wantSerial = false; }
    void ELoutput::includeSerial() { wantSerial = true; }

    void ELoutput::useFullContext() { wantFullContext = true; }
    void ELoutput::useContext() { wantFullContext = false; }

    void ELoutput::separateTime() { wantTimeSeparate = true; }
    void ELoutput::attachTime() { wantTimeSeparate = false; }

    void ELoutput::separateEpilogue() { wantEpilogueSeparate = true; }
    void ELoutput::attachEpilogue() { wantEpilogueSeparate = false; }

    // ----------------------------------------------------------------------
    // Changing ostream:
    // ----------------------------------------------------------------------

    void ELoutput::changeFile(std::ostream& os_) {
      os.reset(&os_, do_nothing_deleter());
      emitToken("\n=======================================================", true);
      emitToken("\nError Log changed to this stream\n");
      std::string const& ftime = formatTime(time(nullptr));  // Change log 7
      emitToken(ftime, true);
      emitToken("\n=======================================================\n", true);
    }

    void ELoutput::changeFile(const std::string& filename) {
      os.reset(new std::ofstream(filename.c_str(), std::ios /*_base*/ ::app), close_and_delete());
      emitToken("\n=======================================================", true);
      emitToken("\nError Log changed to this file\n");
      std::string const& ftime = formatTime(time(nullptr));  // Change log 7
      emitToken(ftime, true);
      emitToken("\n=======================================================\n", true);
    }

    void ELoutput::flush() { os->flush(); }

    // ----------------------------------------------------------------------

  }  // end of namespace service
}  // end of namespace edm