logger.hh

Go to the documentation of this file.

#ifndef _DRAMA2_LOGGER_INC
#define _DRAMA2_LOGGER_INC
/*
 * History:
     01-Jul-2014 - TJF - Original version
     11-May-2015 - TJF - Start of history after development.
                         Revert to using Task * instead of shared_ptr<Task>
                          since using the later would not delay the 
                          construction of the logger until after the
                          Task constructor has returned, which has its own
                          problems
     30-Sep-2016 - TJF - DramaCtxMapType now has a pair of item each thread,
                          a string and the drama context, rather then just
                          the drama context.  The string is supplied when
                          threads are registered and is output in a new
                          field in the log file.
 
 * The above ID is for Doxygen, this one has the format ACMM is looking for.
 * "@(#) $Id$"
 */
 
 
// Define to enable the LogStream class - which does not work
//  on some systems.  Currently disabled all the time until we understand
//  what is wrong in more detail.
 
//#define D2_PROVIDE_LOG_STREAM
 
#include "DitsTypes.h"
#include "Ers.h"
#include <iostream>
#include <fstream>
#if defined(__GNUC__) &&  !defined(__clang__)
#define _DRAMA_HaveGnuFileBufExt
#define _DRAMA_GnuFileBufExtOnly(_A_) _A_
#include <ext/stdio_filebuf.h>  // __gnu_cxx::stdio_filebuf
#else
#define _DRAMA_GnuFileBufExtOnly(_A_) _A_
#endif
 
#include <map>
#include <thread>
 
/*
 * Usable log levels.  
 *
 * When a log call is made, if the "and" of the supplied log level
 * and the currently enabled log level is non-zero, then the message
 * is logged.
 */
#define  D2LOG_ALL        0xFFFFFFFF  
#define  D2LOG_STARTUP    0x01        
#define  D2LOG_ERRORS     0x02        
#define  D2LOG_ACTENT     0x04        
#define  D2LOG_ACTEXIT    0x08        
#define  D2LOG_INST       0x10        
#define  D2LOG_MSG        0x20        
#define  D2LOG_DEBUG      0x40        
#define  D2LOG_COMMS      0x80        
#define  D2LOG_USER1      0x100       
#define  D2LOG_USER2      0x200       
#define  D2LOG_USER3      0x400       
#define  D2LOG_USER4      0x800       
#define  D2LOG_ARGS       0x1000      
#define  D2LOG_DRAMA2     0x2000      
#define  D2LOG_ALWAYS     0x40000     
#define  D2LOG_ALWAYS_S   0x80000     
namespace drama { 
    namespace logging { 
 
        /*
         * We will have a map of the DRAMA context associated with each thread.
         */
        typedef std::map<std::thread::id, std::pair<std::string, Dits___CurActType>> DramaCtxMapType;
        typedef DramaCtxMapType::iterator DramaCtxMapIter;
        typedef DramaCtxMapType::const_iterator DramaCtxMapIterConst;
 
        class Logger;
 
        /*
         * This object fetches and formats the time.  The UpdateTime() function
         * updates the internal time and TimeToString() returns the formated
         * time string.
         */
        class LogTime {
    
        private:
            /* 
             * We keep about the formated time we last used - to avoid doing it 
             * again.  We also need the time itself - for which we use a 
             * "long int" to avoid having to include time.h for this module.
             */
            long int _LastTime;     //  Last time we logged at 
            int      _millisec;     //  milliseconds within the second 
            char     _timeStr[30];  // Formated time string
 
            // User specified offset to apply (for debugging)
            static long int _s_userTimeOffset; 
 
        public:
            LogTime();
            
            /*
             * Readout the current system time and update the internal time 
             * string.  If altTime is non-zero, it is a pointer to a time to use 
             * instead of the current system time.
             *
             * If updateInternalTime is true, then the internal value kept for the
             * last time is updated and the log file changed if appropiate.  
             * Otherwise only the string avialable to TimeString() is updated.  
             * We set this to false if we don't want to change the log file on a 
             * day change.
             *
             * day returns the current unix day (since 1 Jan 1970), but only
             * if the time in seconds has changed in the last call, otherwise
             * returns set to -1.
             *
             */
            void UpdateTime(bool updateInternalTime,
                            int *day,
                            const IMP_AbsTime *altTime);
 
            /*
             * Force UpdateTime to re-read the time on the next read.  
             *  This is necessary to force a fetch of the day.
             */
            void Reset() {
                _LastTime = 0;
            }
     
            /*
             * Return the time string.
             */
            const char *TimeString() const { return _timeStr; };
            
            /*
             * Return the time itself.
             */
            long GetTime() const { return _LastTime; };
            /*
             * Return the milliseconds point within the second.
             */
            int Millisec() const { return _millisec; };
            /*
             * Set/Get the current time offset.
             */
            static void SetTimeOffset(long int t) { _s_userTimeOffset = t; }
            static long int GetTimeOffset() { return _s_userTimeOffset; }
 
 
            ~LogTime();
    
        }; // class LogTime
 
        /* LogFileStream is a sub-class of std::ofstream which provides some
         * special features around the type of file to be used for std::ofstream.
         *
         * In particular, it allows us to use a GCC file buffer, which allows
         * us to to create a file buffer(NOT an iostream yet) from FILE *, so
         * that we can:
         *
         *   1.  Access the file descriptor (so we can sync the file to disk)
         *   2.  Wrap up access to a popen() call.
         *
         * This is currently GCC specific (what are we to do on the Macs?), but
         *  having these features in a class will allow us to isolate the changes
         *  needed.
         * 
         * I found how to do this from
         *   http://www.unix.com/programming/151517-porting-ofstream-attach-linux-gcc.html
         * Proper documentation at
         *   http://gcc.gnu.org/onlinedocs/libstdc++/manual/ext_io.html
         *
         *   Might only work from libstdc++ 3.1 onwards.  Need an equivalent
         *   for CLang (but haven't found one as of 21-May-2015.)
         */
        class LogFileStream : public std::ofstream {
        private:
#ifdef _DRAMA_HaveGnuFileBufExt            
            /*
             * Pointer to the gcc stdio_filebuf() object.  Non-portable
             * code - may need to replace with other compilers, e.g. CLang.
             */
            std::unique_ptr<__gnu_cxx::stdio_filebuf<char> > _fileBuf;
            /*
             * A file pointer, being used when we open with popen().
             */
            FILE *_pFile = 0;
#endif
 
        public:
            /* Constructor.  Don't open the file with these */
            LogFileStream() {}
            /* Destructor */
            ~LogFileStream();
            /*
             * Open the stream as the input to a command - using open().
             */
#ifdef _DRAMA_HaveGnuFileBufExt            
            void popen(const std::string &command);
#endif
            /*
             * Open the stream to a file.  This is provided so that we
             * can implement fsync(), below.
             */
            void fopen(const std::string &filename);
 
            /*
             * Since the file to disk.
             */
            void fsync();
 
            /*
             * Close the file.  Overrides ofstream::open();
             *   For some reason, override flag does not work here.
             */
            void close();
 
#ifdef _DRAMA_HaveGnuFileBufExt            
            /*
             * Indicate if the file is open. Override ofstream::is_open().
             *   For some reason, override flag does not work here.
             */
            bool is_open() const  {
                if (!_fileBuf) return false;
                return _fileBuf->is_open();
            }
            /*
             * Returns rdbuf - non-standard operation, but we need to override
             * ofstream::rdbuf.
             *
             *   For some reason, override flag does not work here.
             */
            __filebuf_type* rdbuf() const  { 
                DramaTHROW(DRAMA2__PROG_ERROR,
                           "Attempt to call LogBuffer::rdbuf");
            }
 
#endif
 
            
        };
 
        /*
         * This class is used by Logger to ensure we have the correct
         * DRAMA Context (Action/UFACE details) for the current thread.  
         * It is a friend of Logger, as it needs access to items the 
         * general public does not need.
         *
         * The constructor must work out if the current thread is the DRAMA
         * main thread (that invoking RunDrama()) or an otherwise known thread.
         * If the later, it must switch the DRAMA context to that of the known
         * thread and reverse that effect when the destructor is run.
         *
         * This class implements the Resource Acquisition Is Initialization
         * design pattern, but is intended to be used for Scope-based Resource 
         * Management only.
         */
        class GrabLogContext {
            bool _onKnownThread  = false;
            bool _onCreateThread = false;
            bool _onRunThread    = false;
            Dits___CurActType _entryContext;
            std::string       _func;
        public:
            GrabLogContext(const Logger &);
            ~GrabLogContext();
            // Returns true if this thread has a DRAMA context registered.
            bool IsKnownThread() const {
                return _onKnownThread;
            }
            // Returns true if this is the thread that created the DRAMA task.
            bool IsDramaCreateThread() const {
                return _onCreateThread;
            }
            // Returns true if this is the thread that run the DRAMA task.
            bool IsDramaRunThread() const {
                return _onRunThread;
            }
            // Returns the function name associated withe the thread.
            std::string FuncName() const {
                if (_onCreateThread)
                    return "";
                if (_onRunThread)  // No DRAMA creation thread, but am running DRAMA.
                    return "<<::RunDrama>>";
                if (_onKnownThread)
                    return _func;
                else
                    return "<<ukn thd fnc>>";
            }
        };
 
        class LogStreamBuf : public std::streambuf {
        
        private:
            Logger *_theLogger;
            std::string _prefix;            // Log prefix string.
            unsigned _level;                // Log level we write at.
           
        protected:
            // Buffer for messages to output.
            static const int BUFFER_SIZE = 200;
            char _buffer[BUFFER_SIZE+1];
            
            /*
             * Buffer flush operation.  returns number output.
             */
            int flushBuffer();
            /*
             * Invoked if adding a character would overflow the buffer.
             * We Add it (since our constructor ensured there is sufficient
             * space and then flush the buffer.
             */
            virtual int_type overflow(int_type c)  override {
                if (c != EOF)
                {
                    // insert character into buffer
                    *pptr() = c;
                    pbump(1);
                }
                // flush the buffer
                if (flushBuffer() == EOF)
                {
                    return EOF;
                }
                return c;
                
            }
            /*
             * Sync the file - just flushes to the log file.
             */
            virtual int sync() override {
                if (flushBuffer() == EOF) {
                    return -1;
                }
                return 0;
            }
            
        public:
            LogStreamBuf(Logger *theLogger, unsigned level, const std::string &prefix) :
                    _theLogger(theLogger),
                    _prefix(prefix),
                    _level(level) {
                /*
                 * Need to provide our buffer to the std::Streambuf base
                 * class.  One character less to ensure the last character
                 * causes an overflow.
                 */
                setp(_buffer, _buffer+(BUFFER_SIZE-1));
            }
            virtual ~LogStreamBuf() {
                /*
                 * We want to output what is left, but any exception now
                 * (which may be caused by DRAMA failing to send the message
                 * for various reasons), if left uncaught, will cause the
                 * program to crash (can't throw from destructors), so
                 * catch any DRAMA exception and use stderr.
                 */
                try 
                {
                    sync();
                }
                catch (drama::Exception &e)
                {
                    fprintf(stderr,"DRAMA Exception thrown by drama::~LogStreamBuf()\n");
                    fprintf(stderr,"%s\n", e.toString().c_str());
                    fprintf(stderr,"DRAMA Status = 0x%lX, %s\n",
                            static_cast<long int>(e.dramaStatus()),
                            e.dramaStatusStr().c_str());
                    
                }
            }
 
 
            LogStreamBuf(const LogStreamBuf &source) = delete;
 
            LogStreamBuf& operator = (const LogStreamBuf &rhs) = delete;
 
            LogStreamBuf(LogStreamBuf &&source) noexcept : 
                _theLogger(source._theLogger),
                _prefix(source._prefix),
                _level(source._level) {
                    source._theLogger = nullptr;
            }
 
 
            LogStreamBuf& operator=(LogStreamBuf &&rhs) noexcept {
 
                this->_theLogger = rhs._theLogger;
                this->_level     = rhs._level;
                this->_prefix    = std::move(rhs._prefix);
 
                rhs._theLogger = nullptr;
                return *this;
            }
 
 
            
        };  //class  LogStreamBuf
 
#ifdef D2_PROVIDE_LOG_STREAM // Currently disabled.  Does not work under CLang compiler, unclear why
 
// LogStream not working under CLang, later versions.  unclear why, but
//  appears related to copy/assignment.  tocker would crash when
//  attempting to use a LogStream created by CreateLogStream() below.
 
        class LogStream : public std::ostream {
            friend class Logger;
        private:
            LogStreamBuf _buf;
            /* Construct a LogStream object.
             * 
             * Private since only normally constructed by the Logger object
             * CreateLogStream() method.
             *
             * @param theLogger  A pointer to the DRAMA logger object
             * @param level      The level at which the events will be written
             * @param prefix     The prefix for the log messages.
             */
            LogStream(Logger *theLogger, unsigned level, const std::string &prefix) :
                _buf(theLogger, level, prefix) {
                /* 
                 *  Set the buffer address for ostream.
                 */
                rdbuf(&_buf);
            }
 
        public:
            LogStream(const LogStream &source) = delete;
 
            LogStream& operator = (const LogStream &rhs) = delete;
 
            LogStream(LogStream &&source) noexcept : _buf(std::move(source._buf)){ }
 
 
            LogStream& operator=(LogStream &&rhs) noexcept {
                
                _buf = std::move(rhs._buf);
                return *this;
            }
 
            
        }; //class  LogStream.
#endif        
 
 
        class Logger {
 
            friend class GrabLogContext;
        private:
            /*
             * This internal object is used to fetch and format the time.
             */
            LogTime _timer;
 
 
            /* Structure used to maintain level names */
            typedef struct  { 
                int minsig; unsigned level; const char *string; 
            } LevelStruct;
 
            /* Translations of various codes to strings */
            static const LevelStruct _s_LevelNames[];
            static const char *_s_RescheduleReasons[];
            static const char *_s_Requests[];
            static const char *_s_PathStatus[];
            static const char *_s_MessageTypes[];
            
            /* Maximum length of messages */
            static const int _s_MsgLen;
 
            /* Current Logging levels.*/
            unsigned _currentLevels = 
                (D2LOG_ALWAYS | D2LOG_ALWAYS_S | D2LOG_MSG | D2LOG_ERRORS);
 
 
            /*
             * If we true,then logging of MsgOut messages is disabled.  Used when
             *  we want to output something to the screen but not to the log file.
             */
            bool _disableMsgOut = false;
 
            /* Log file stream and name. */
            LogFileStream _logFile;
            //std::ofstream _logFile;
            std::string _logFileName;
 
            /*
             * LogDay contain the day number in the year.  We use it to work
             * out if the day has changed.
             */
            int _logDay = 0;
 
            /*
             * Pointer to the DRAMA task we are part of.
             * The pointer is const - we never change it after the constructor.
             *  The task pointed to is NOT const - since we can operate on it.
             */
            Task        * const _theTask;  
            /*
             * Directory and system names supplied to constructor.
             */
            std::string _directory;
            std::string _system;
            /*
             * Set true to always flush the log file.
             */
            bool _flushAlways = false;
            /*
             * Set true to turn of fsync() operation when flushing
             */
            bool _noFsync = false;
            /*
             * Set true to disable LogFlush()
             */
            bool _noLogFlush = false;
            /*
             * Set true when the log is flushed, cleared when messages
             * are written.
             */
            bool _flushed = false;
 
            /*
             * Last write to log file failed.
             */
            bool _failed = false;
            /*
             * Are we compressing data on the fly)
             */
            bool _compress = false;
            FILE *_compressFD = nullptr;
            /*
             * This variable records the approximate file size - in particular, 
             * the amount of data we have written to the file using 
             * Logger::LogMessage(), the core logging routine.  It does not 
             * record various bits of header information.
             *
             * We use this allow us to create a new log file every 512 MB - to 
             * avoid file system file size problems which occur at about 1 GB on 
             * older file systems..  
             */
            INT32 _fileSize = 0;
 
            /*
             * Should we add a column with the thread ID.  This makes
             * us incompatible with GIT Logger.
             */
            bool _logThreadID = false;
            /*
             * A MAP of thread to DRAMA context.  Allows us to find the
             * appropriate DRAMA context information for any registered
             * thread - register threads with the RegisterThread() method.
             */
            DramaCtxMapType  _threadToDRAMAContextMap;
            /*
             * The ID of the main thread - the one that created the logger
             * (should be the thread running the DRAMA task).
             */
            std::thread::id  _mainThreadId;
            /*
             * Used to actually sync the log file.
             */
            void SyncFile(const char *from_where);
 
            /*
             * We need a static routine to implement the log level action
             * which can then call the object routine Action.
             */
            static void LogLevelAction(StatusType *status);
            void Action(StatusType *status);
 
            /*
             * Methods supporting the constructor and the Open() method.
             */
            void CreateLogLevelAction(StatusType *status);
            void CreateParameters(StatusType *status);
            void InitialiseLogLevel(StatusType *status);
            void LogTaskVersionInfo();
 
            /*
             * static routines which are passed to DRAMA to implement the
             * DRAMA logging system.  See DitsSetLogSys().
             */
            static DVOID ActionEntryLog(DVOIDP client_data,StatusType *status);
            static DVOID ActionReturnLog(
                DVOIDP client_data,
                int argDelete,
                SdsIdType argOut,
                DitsReqType request,
                int delaySet,
                DCONSTV DitsDeltaTimeType * delay,
                StatusType exitStatus,
                StatusType *status);
            static DVOID GetPathLog(
                DVOIDP client_data,
                DCONSTV  char * name,
                DCONSTV  char * node,
                int flags,
                DCONSTV DVOIDP info,
                DitsPathType path,
                DitsTransIdType transid,
                StatusType *  status);
            static  DVOID MsgSendLog(
                DVOIDP client_data,
                long int flags,
                DitsPathType path,
               DitsTransIdType transid,
                DCONSTV DitsGsokMessageType *  message,
                StatusType *status);
            static DVOID LoadLog(
                DVOIDP client_data,
                DCONSTV char * Machine,
                DCONSTV char * TaskName,
                DCONSTV char * ArgString,
                long int Flags,
                DCONSTV DitsTaskParamType * TaskParams,
                DitsTransIdType transid,
                StatusType *status);
            static  DVOID NotifyReqLog(
                DVOIDP client_data,
                int notifyRequested,
                DitsPathType path,
                DitsTransIdType transid,
                StatusType *status);
            static DVOID MsgOutLog(
                DVOIDP client_data,
                DCONSTV char * message,
                StatusType *status);
            static DVOID LogMsgLog(
                DVOIDP client_data,
                unsigned    level,
                DCONSTV char * prefix,
                DCONSTV char * fmt,
                va_list ap,
                StatusType *status);
            
            static DVOID LogTrigger(
                DVOIDP client_data,
                SdsIdType arg,
                StatusType *status);    
            
            static DVOID LogTrigBulk(
                DVOIDP client_data,
                DCONSTV DVOIDP SharedMemInfo,
                int sds,
                int NotifyBytes,
                DitsTransIdType transid,
                StatusType *status);
            
            static DVOID LogSignal(
                DVOIDP client_data,
                long int actptr,
                DCONSTV DVOIDP ptr,
                SdsIdType arg,
                StatusType *status);    
            
            static DVOID LogBulkSend(
                DVOIDP client_data,
                DCONSTV long int flags,
                DCONSTV DitsPathType path,
                DCONSTV DVOIDP SharedMemInfo,
                int NotifyBytes,
                DitsTransIdType transid,
                DCONSTV DitsGsokMessageType *  message,
                StatusType * status);  
            
            
            static DVOID ErsLog(DVOIDP logArg, DCONSTV ErsMessageType * message,
                                StatusType * status);
            static DVOID LogShutdown(
                DVOIDP client_data,
                int taskShutdown,
                StatusType *status);
            
            static DVOID LogFlush(DVOIDP client_data, StatusType *status);
            static DVOID LogInfo(DVOIDP client_data, StatusType *status);
    
        
            /*
             * The actual routine which logs to the file etc.  If altTime is 
             * specified, then the log message is taged with that time, otherwise 
             * it is tagged with the current time
             */
            void LogMessage(const char *prefix,
                            const char *message,
                            const IMP_AbsTime *altTime=0);
            
 
            /*
             * Methods to set the logging levels from a string.
             */
            void SetLevels(const std::string &s, StatusType *status);
 
            /* Methods to fetch logging levels. */
            std::string GetLevels() const;
 
            /* Support function for GetLevels */
            void LevelCheckAndAdd(unsigned index, std::string *s) const;
            
            void OpenLogFile(bool day_rollover, bool size);
            void OpenIt(const std::string &BaseLogFileName);
            /* Check if the file size has got too large */
            void CheckFileSize();
 
            /* Check if we should use compress mode */
            void CheckCompressMode();
            /* Close log file */
            void CloseLogFile();
            
            /* Create a new log file name */
            static std::string NewName(const std::string &BaseLogFileName, int counter);
 
            /* Has a log file named already been used */
            static bool NameUsed(const std::string &name);
 
            /* Check if the day has changed.  If it has, reopen the log file for
             * the new day.
             */
            void CheckDayChange(int newDay);
 
            /*
             * Assignment operation and Copy constructor deleted
             * to avoid misuse.
             */
            void operator=(const Logger&) = delete;
            Logger(const Logger&) = delete;
 
 
            /*
             * A class used to temporally disable MsgOut logging.
             *
             * This class implements the Resource Acquisition Is Initialization
             * design pattern, but is intended to be used for Scope-based Resource 
             * Management only.
             */
            class MsgOutNoLog {
            private:
                Logger *_theLogger;
                bool  _previousState;
            public:
                MsgOutNoLog(Logger *theLogger) :
                    _theLogger(theLogger),
                    _previousState(theLogger->_disableMsgOut) {
                    theLogger->_disableMsgOut = true;
                }
                ~MsgOutNoLog() {
                    _theLogger->_disableMsgOut = _previousState;;
                }
            };
            
        public:
            
            Logger(Task * dramaTask);
            void Open(const std::string &system, 
                      const std::string &dir="", 
                      bool compress=false);
 
 
            ~Logger();
 
 
 
            static void SetTimeOffset(long int t){LogTime::SetTimeOffset(t); }
    
            void Log(unsigned level, bool nofmt, const char *prefix,
                     const char *fmt, ...)
#ifdef __GNUC__
                __attribute__ ((format (printf, 5, 6))) /* Note, method version of __attribute__ needs 1 added to each argument over non-method version.  */
#endif
                ;
 
 
            template<typename... Types>
            void SLog(unsigned level, const std::string &prefix,
                      const std::string &fmt, Types... args) {
                /*
                 * Our approach is to write the output to a string, via
                 * SafePrintf(), then output that in one operation. 
                 */
                std::stringstream sstrm;
                drama::SafePrintf(sstrm, fmt.c_str(), args...);
                DGCC_DIAG_OFF(format-security) // Since formating disabled, no problem
                Log(level, true, prefix.c_str(), sstrm.str().c_str());
                DGCC_DIAG_OFF(format-security)
 
            }
            template<typename... Types>
            void SLog( std::ostream &ostream,
                       unsigned level, const std::string &prefix,
                       const std::string &fmt, Types... args) {
                /*
                 * Our approach is to write the output to a string, via
                 * SafePrintf(), then output that in one operation. 
                 */
                std::stringstream sstrm;
                drama::SafePrintf(sstrm, fmt.c_str(), args...);
                Log(level, true, prefix.c_str(), sstrm.str().c_str());
 
                ostream << sstrm.str() << std::endl;
            }
 
            void Log(const IMP_AbsTime *time,
                     unsigned level, bool nofmt, const char *prefix,
                     const char *fmt, ...)
#ifdef __GNUC__
                __attribute__ ((format (printf, 6, 7)))
#endif
                ;
 
            void Set(unsigned newLevels);
      
            void Unset(unsigned disableLevels);
 
            void RegisterThread(const Dits___CurActType &dramaContext,
                                std::thread::id threadId=std::this_thread::get_id(),
                                const char* func = "*unnamed func*");
            void RegisterThread(std::thread::id threadId=std::this_thread::get_id(),
                                const char* func = "*unamed func*");
 
 
            void RegisterThread(std::thread::id sourceThread, 
                                std::thread::id newThread,
                                const char* func = "*unnamed func*");
 
 
 
            void RegisterThreadNoDramaCtx(
                std::weak_ptr<Task> dramaTask,
                                const char* func = "*non-drama*");
 
 
 
#ifdef D2_PROVIDE_LOG_STREAM // Currently disabled.
// Not working under CLANG - Mac  ElCapitan and Serria.  
//   Problem with copy/assignment in LogStream!!!!  (I think).
            LogStream CreateLogStream(unsigned level, 
                                      const std::string &prefix) {
                return LogStream(this, level, prefix);
            }
#endif
 
        }; // class Logger
 
 
 
 
    } // namespace logging
 
} // namespace drama
 
#endif