Logger.hxx

Go to the documentation of this file.

 
#ifndef LOGGING_INCLUDE_LOGGING_DETAIL_LOGGER_HXX_
#define LOGGING_INCLUDE_LOGGING_DETAIL_LOGGER_HXX_
 
#include <stdlib.h>             // setenv
 
 
/*  verstrace_user
    Only log and debug "levels" (or "streams") are supported
 */
#if defined(__has_feature)
#  if __has_feature(thread_sanitizer)
__attribute__((no_sanitize("thread")))
#  endif
#endif
static void verstrace_user(struct timeval */*tvp*/, int TID, uint8_t lvl, const char* insert
    , const char* file, int line, const char* function, uint16_t nargs, const char *msg, va_list ap)
{
 
    size_t printed = 0;
    int    retval;
    const char *outp;
    char   obuf[TRACE_USER_MSGMAX];
 
    if ((insert && (printed = strlen(insert))) || nargs)
    {
        /* check insert 1st to make sure printed is set */
        // assume insert is smaller than obuf
        if (printed) {
            retval = snprintf(obuf,sizeof(obuf),"%s ",insert );
            printed = TRACE_SNPRINTED(retval,sizeof(obuf));
        }
        if (nargs) {
            retval = vsnprintf(&(obuf[printed]), sizeof(obuf) - printed, msg, ap); // man page say obuf will always be terminated
            printed += TRACE_SNPRINTED(retval,sizeof(obuf)-printed);
        } else {
            /* don't do any parsing for format specifiers in the msg -- tshow will
               also know to do this on the memory side of things */
            retval = snprintf( &(obuf[printed]), sizeof(obuf)-printed, "%s", msg );
            printed += TRACE_SNPRINTED(retval,sizeof(obuf)-printed);
        }
        if (obuf[printed-1] == '\n')
            obuf[printed-1] = '\0';  // DONE w/ printed (don't need to decrement
        outp = obuf;
    } else {
        if (msg[strlen(msg)-1] == '\n') { // need to copy to remove the trailing nl
            retval = snprintf( obuf, sizeof(obuf), "%s", msg );
            printed = TRACE_SNPRINTED(retval,sizeof(obuf));
            if (obuf[printed-1] == '\n')
                obuf[printed-1] = '\0';  // DONE w/ printed (don't need to decrement
            outp = obuf;
        } else
            outp = msg;
    }
    // LocalContext args: 1-"package_name" 2-"file" 3-"line" 4-"pretty_function" 5-"include_stack"
    ers::LocalContext lc(
                         reinterpret_cast<char*>(idx2namsPtr(TID)),
                         file, line, function, DEBUG_FORCED );
    //std::ostringstream ers_report_impl_out_buffer;
    //ers_report_impl_out_buffer << outp;
    if (lvl < TLVL_DEBUG) { // NOTE: at least currently, TLVL_LOG is numerically 1 less than TLVL_DEBUG
        //auto d = std::chrono::seconds{tvp->tv_sec} + std::chrono::microseconds{tvp->tv_usec};
        //std::chrono::system_clock::time_point tp{d};
        // PROTECTED - ers::Issue iss( ers::Issue( ers::Severity(ers::Log), tp, lc, outp, std::vector<std::string>(), std::map<std::string,std::string>(), nullptr ));
        ers::log(   ers::InternalMessage(lc,outp) );
    } else {
        ers::debug( ers::InternalMessage(lc,outp),lvl-TLVL_DEBUG );
    }
}
 
SUPPRESS_NOT_USED_WARN
static void erstrace_user(struct timeval *tvp, int TID, uint8_t lvl, const char* insert, const char* file, int line, const char* function, uint16_t nargs, const char *msg, ...)
{
    va_list ap;
    va_start(ap, msg);
    verstrace_user(tvp, TID, lvl, insert, file, line, function, nargs, msg, ap);
    va_end(ap);
}
 
#pragma GCC diagnostic push
#pragma GCC diagnostic ignored "-Wvarargs"
SUPPRESS_NOT_USED_WARN
static void erstrace_user(struct timeval *tvp, int TID, uint8_t lvl, const char* insert, const char* file, int line, const char* function, uint16_t nargs, const std::string& msg, ...)
{
    va_list ap;
    va_start(ap, msg);
    verstrace_user(tvp, TID, lvl, insert, file, line, function, nargs, &msg[0], ap);
    va_end(ap);
}   /* trace */
#pragma GCC diagnostic pop
 
 
 
// The following allow an ers::Issue to be streamed into TLOG() or TLOG_DEBUG(N)
inline void operator<<(TraceStreamer& x, const ers::Issue &r)
{
    if (x.do_m) {
        x.line_ = r.context().line_number();
        x.msg_append(r.message().c_str());
        // MAY NEED TO APPEND CHAINED ISSUE???
        // const ers::Issue *issp = &r;
        // while ((issp=issp->cause())) {
        // }
    }
    if (x.do_s) {
        if      (x.lvl_==TLVL_INFO) ers::info(  r );                    \
        else if (x.lvl_==TLVL_LOG)  ers::log(   r );                    \
        else                        ers::debug( r, x.lvl_-TLVL_DEBUG ); \
        x.do_s = 0;
    }
}
 
inline void operator<<(TraceStreamer& x, const ers::InternalMessage &r)
{
    if (x.do_m) {
        x.line_ = r.context().line_number();
        x.msg_append(r.message().c_str());
        // MAY NEED TO APPEND CHAINED ISSUE???
    }
    if (x.do_s) {
        if      (x.lvl_==TLVL_INFO) ers::info(  r );                    \
        else if (x.lvl_==TLVL_LOG)  ers::log(   r );                    \
        else                        ers::debug( r, x.lvl_-TLVL_DEBUG ); \
        x.do_s = 0;
    }
}
 
 
namespace {  // unnamed namespace (i.e. static (for each compliation unit only))
 
    class ErsFatalStreamer
    {
    public:
        inline ErsFatalStreamer &operator<<(const ers::Issue &r)
        {
            ers::fatal( r );
            return *this;
        }
    };  // class ErsFatalStreamer
 
    class ErsErrorStreamer
    {
    public:
        inline ErsErrorStreamer &operator<<(const ers::Issue &r)
        {
            ers::error( r );
            return *this;
        }
    };  // class ErsErrorStreamer
 
    class ErsWarningStreamer
    {
    public:
        //ErsWarningStreamer( ers::LocalContext c ) : _ctx(c) {}
        //ers::LocalContext _ctx;
        inline ErsWarningStreamer &operator<<(const ers::Issue &r)
        {
            // would be nice of the "context" could be created from the streamer instance
            ers::warning( r );
            return *this;
        }
    };  // class ErsWarningStreamer
    class ErsInfoStreamer
    {
    public:
        //ErsInfoStreamer( ers::LocalContext c ) : _ctx(c) {}
        //ers::LocalContext _ctx;
        inline ErsInfoStreamer &operator<<(const ers::Issue &r)
        {
            // would be nice of the "context" could be created from the streamer instance
            ers::warning( r );
            return *this;
        }
    };  // class ErsInfoStreamer
    class ErsLogStreamer
    {
    public:
        //ErsLogStreamer( ers::LocalContext c ) : _ctx(c) {}
        //ers::LocalContext _ctx;
        inline ErsLogStreamer &operator<<(const ers::Issue &r)
        {
            // would be nice of the "context" could be created from the streamer instance
            ers::warning( r );
            return *this;
        }
    };  // class ErsLogStreamer
}  // namespace ""
 
 
 
// The following allows "erstrace" to be included in the ERS configuration via
// DUNEDAQ_ERS_{FATAL,ERROR,WARNING} environment variables.
#include <ers/OutputStream.hpp>
namespace ers
{
struct erstraceStream : public OutputStream {
        void write( const ers::Issue & issue )
        {
            ers::Severity sev = issue.severity();
            uint8_t lvl_=TLVL_DEBUG;
            switch (sev.type) {
            case ers::Debug:       lvl_=TLVL_DEBUG+sev.rank;break;
            case ers::Log:         lvl_=TLVL_LOG;           break;
            case ers::Information: lvl_=TLVL_INFO;          break;
            case ers::Warning:     lvl_=TLVL_WARNING;       break;
            case ers::Error:       lvl_=TLVL_ERROR;         break;
            case ers::Fatal:       lvl_=TLVL_FATAL;         break;
            }
            struct { char tn[TRACE_TN_BUFSZ]; } _trc_;
            if (TRACE_INIT_CHECK(trace_name(TRACE_NAME,issue.context().file_name(),_trc_.tn,sizeof(_trc_.tn)))) {
                if (traceControl_rwp->mode.bits.M && (traceLvls_p[traceTID].M & TLVLMSK(lvl_))) {
                    struct timeval lclTime;
                    std::chrono::system_clock::time_point tp{issue.ptime()};
                    //auto micros = std::chrono::duration_cast<std::chrono::microseconds>(tp.time_since_epoch());
                    std::chrono::microseconds micros = std::chrono::duration_cast<std::chrono::microseconds>(tp.time_since_epoch());
                    lclTime.tv_sec  = micros.count() / 1000000;
                    lclTime.tv_usec = micros.count() % 1000000;
                    int traceID = trace_name2TID( trace_name(TRACE_NAME,issue.context().file_name(),_trc_.tn,sizeof(_trc_.tn)) );
                    std::string complete_message = issue.message();
                    const ers::Issue *issp = &issue;
                    while ((issp=issp->cause())) {
                        char fbuf[0x100], tbuf[0x40];
                        int strip_ns=1;
                        tp = issp->ptime();
                        std::chrono::milliseconds millis
                            = std::chrono::duration_cast<std::chrono::milliseconds>(tp.time_since_epoch());
                        struct tm tm_s;
                        time_t secs  = millis.count() / 1000;
                        localtime_r(&secs, &tm_s);
                        if (strftime(tbuf, sizeof(tbuf), "%Y-%b-%d %H:%M:%S", &tm_s) == 0)
                            tbuf[0]= '\0';
                        complete_message += "\n\tcaused by: " + std::string(tbuf);
                        int milliseconds = millis.count() % 1000;
                        sprintf(tbuf,",%03d ",milliseconds);
                        complete_message += std::string(tbuf);
                        trace_func_to_short_func(issp->context().function_name(), fbuf, sizeof(fbuf), strip_ns);
                        complete_message += ers::to_string(issp->severity())
                            + " [" + fbuf + " at "
                            + trace_path_components(issp->context().file_name(),0)
                            + ":" + std::to_string(issp->context().line_number())
                            + "] " + issp->message();
                    }
                    trace(&lclTime, traceID, lvl_, issue.context().line_number(),
                          issue.context().function_name(),
                          0 TRACE_XTRA_PASSED, complete_message.c_str());
                }
            }
            chained().write( issue );
        }
};
}
ERS_REGISTER_OUTPUT_STREAM( ers::erstraceStream, "erstrace", ERS_EMPTY )    // last param is "param" 
 
 
// Support macros
#define SL_FRC(lvl) ((lvl)>=0 && (lvl)<TLVL_DEBUG)
 
#define LOG0_()              
#define LOG1_(value)            value,
#define LOG2_(value, value1)    value , value1,
#define COMMA_IF_PARENS(...)  ,
#define LPAREN                (
#define EXPAND_(...)           __VA_ARGS__
#define CHOOSE_(...)           EXPAND_(LOG__  LPAREN \
                                     __VA_ARGS__ COMMA_IF_PARENS __VA_ARGS__ COMMA_IF_PARENS __VA_ARGS__ (), \
                                     LOG2_, impossible, LOG2_, LOG1_, LOG0_, LOG1_, ))
#define LOG__(a0, a1, a2, a3, a4, a5, arg, ...) arg
#define _tlog_ARG2( a1,a2,...)    tlog_ARG2(a1,a2,__VA_ARGS__)
#define _tlog_ARG3( a1,a2,a3,...) tlog_ARG3(a1,a2,a3,__VA_ARGS__)
 
 
#endif // LOGGING_INCLUDE_LOGGING_DETAIL_LOGGER_HXX_