Make ScopeTracker thread safe via TLS (thread local storage)

[libi2ncommon] / src / logfunc.cpp

/*
The software in this package is distributed under the GNU General
Public License version 2 (with a special exception described below).

A copy of GNU General Public License (GPL) is included in this distribution,
in the file COPYING.GPL.

As a special exception, if other files instantiate templates or use macros
or inline functions from this file, or you compile this file and link it
with other works to produce a work based on this file, this file
does not by itself cause the resulting work to be covered
by the GNU General Public License.

However the source code for this file must still be made available
in accordance with section (3) of the GNU General Public License.

This exception does not invalidate any other reasons why a work based
on this file might be covered by the GNU General Public License.
*/
/** @file
 * @brief implementaton of logging functions.
 *
 * @copyright © Copyright 2007-2008 by Intra2net AG
 * 
 * @note Don't call loggers from global constructed objects
 * as this depends on the global object construction sequence.
 */

#include "logfunc.hpp"

#include <syslog.h>
#include <cstdlib>
#include <ctime>
#include <algorithm>
#include <iostream>
#include <fstream>
#include <unistd.h>
#include <string.h>
#include <boost/shared_ptr.hpp>
#include <boost/thread/recursive_mutex.hpp>
#include <boost/thread/thread.hpp>

#include <stringfunc.hxx>
#include <filefunc.hxx>


namespace I2n
{
namespace Logger
{

/**
 * @brief the global logger instance.
 *
 * This may be used in all cases wheer a specialized logger is not available
 * or shouldn't be used for some reason.
 */
PartLogger GlobalLogger("");


namespace
{

/// Global lock for the logger. Used during all syslog operations
/// and modification of our shared local variables.
static boost::recursive_mutex LoggerLock;

/*
** local globals:
*/

static std::string g_ident;
static Facility    g_facility;
static bool        g_syslog_opened = false;
static int         g_max_level= LogLevel::Warning;

static bool g_stderr_log = false;

static std::string g_log_file_name;
static boost::shared_ptr< std::ofstream > g_log_stream_ptr;

/**
 * @brief lookup array for translating our log levels to syslog level.
 */
static int loglevel_2_syslog_level[ LogLevel::_LogLevel_END ] = {
    LOG_EMERG,
    LOG_ALERT,
    LOG_CRIT,
    LOG_ERR,
    LOG_WARNING,
    LOG_NOTICE,
    LOG_INFO,
    LOG_DEBUG
};


/**
 * @brief lookup array for translating our log levels to a short (4 character) tag.
 *
 * These tags are used when logs are written to stderr or into a log file.
 */
static std::string loglevel_2_short_tag[ LogLevel::_LogLevel_END ] = {
    "EMRG",
    "ALRT",
    "CRIT",
    "ERR ",
    "WARN",
    "NOTE",
    "INFO",
    "DBUG"
};


/**
 * @brief a copy of the current identifier used for syslog.
 *
 * Keeping a copy of this ident is necessary since openlog doen't copy it's first
 * argument but copies only the pointer! (what a **censored**!)
 */
static char* syslog_ident= NULL;


/*
** functions:
*/

/**
 * @brief close syslog.
 */
void close_syslog()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (g_syslog_opened)
    {
        closelog();
        if (syslog_ident)
        {
            free(syslog_ident);
            syslog_ident= NULL;
        }
        g_syslog_opened= false;
    }
} // eo close_syslog()


/**
 * @brief open syslog.
 */
void open_syslog()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    close_syslog();
    syslog_ident= strdup(g_ident.c_str());
    openlog( syslog_ident, LOG_CONS|LOG_PID, g_facility);
    g_syslog_opened= true;
} // eo open_syslog()


/**
 * @brief get syslog level from internal log level.
 * @param level log level.
 * @return syslog level
 */
int get_syslog_level( int level )
{
    // Note: Thread safe

    if (level >=0 &&  level < LogLevel::_LogLevel_END)
    {
        return loglevel_2_syslog_level[level];
    }
    return (level<0) ? (LOG_EMERG) : (LOG_DEBUG);
} // eo get_syslog_level(int)


/**
 * @brief get a short tag for the log level (/ message type)
 * @param level the log level
 * @return a short tag for the level.
 */
std::string get_level_tag( int level )
{
    // Note: Thread safe

    if (level >=0 &&  level < LogLevel::_LogLevel_END)
    {
        return loglevel_2_short_tag[level];
    }
    return (level<0) ? loglevel_2_short_tag[0] : loglevel_2_short_tag[ LogLevel::_LogLevel_END -1 ];
} // eo get_level_tag(int)


/**
 * @brief the "real" log function which logs a message at a given level.
 * @param level the log level to log the message at.
 * @param msg the message.
 *
 * Write the message to every enabled log channel.
 *
 * If syslog is enabled the message is passed unmodified to syslog.
 *
 * If a stream log is enabled (stderr or file) then the message is prepended with date, time
 * and process information (like syslog does). The message is splitted at line ends and
 * consecutive lines are indented.
 */
void log_msg( int level, const std::string& msg)
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (not g_syslog_opened and not g_stderr_log and not g_log_stream_ptr)
    {
        // if nothing is opened for logging: we activate syslog!
        enable_syslog(true);
    }

    if (g_syslog_opened)
    {
        ::syslog( get_syslog_level(level), "%s", msg.c_str());
    }
    // file(/stream) logging:
    if (g_stderr_log or g_log_stream_ptr) // add more log "enabled" expressions here...
    {
        // here we need must do something more with the msg...
        std::string new_msg;
        std::string prefix;
        {
            std::ostringstream ostr;
            // add time stamp (syslog like: "Mon DD HH:MM:SS") :
            {
                time_t t = time(NULL);
                char buffer[32];
                std::strftime(buffer, sizeof(buffer),"%b %d %H:%M:%S ", std::localtime(&t));
                ostr << buffer;
            }
            ostr << get_level_tag(level) << " ";
            ostr << g_ident << "[" << getpid() << "]: ";
            prefix= ostr.str();
        }
        {
            {
                std::string indent_string(prefix.size(), ' ');
                std::list< std::string > parts;
                split_string( chomp(msg,"\n"), parts, "\n");
                std::ostringstream ostr;
                ostr << prefix;
                for(std::list< std::string >::const_iterator it= parts.begin();
                    it != parts.end();
                    ++it)
                {
                    if (it != parts.begin())
                    {
                        ostr << indent_string;
                    }
                    ostr << *it << std::endl;
                }
                new_msg= ostr.str();
            }
        }
        if (g_stderr_log)
        {
            std::cerr << new_msg;
        }
        if (g_log_stream_ptr)
        {
            *g_log_stream_ptr << new_msg << std::flush;
        }
    }
} // eo log_msg


/**
 * @brief "real" log function for part messages.
 * @param level the log level.
 * @param part the part(/module) name(/id)
 * @param msg the log message.
 *
 * basically calls @a log(), but prepends the part (if not empty) in square brackets to the message.
 */
void log_part_msg(
    int level,
    const std::string& part,
    const std::string& msg)
{
    // Note: Locking is done in log_msg()

    if (!part.empty())
    {
        std::ostringstream ostr;
        ostr << "[" << part << "] " << msg;
        log_msg(level, ostr.str());
    }
    else
    {
        log_msg(level, msg);
    }
} // eo log_part_msg(int,const std::string&,const std::string&)


/**
 * @brief returns the name of the program (/binary)
 * @return the program name if it could be determined; generated name else.
 *
 * Tries to determine the name of the binary.
 *
 * If no name could be determined, one is built.
 */
std::string get_program_name()
{
    // Note: Thread safe

    std::string result;
    // determine the program name:
    {
        // try to determine the name using the exe link:
        std::string exe_path;
        {
            std::ostringstream ostr;
            ostr << "/proc/" << ::getpid() << "/exe";
            exe_path= ostr.str();
        }
        std::string binary_path= read_link(exe_path);
        if (!binary_path.empty())
        {
            result= basename(binary_path);
        }
    }
    if (result.empty())
    {
        // no program name found up to this point.
        // make a name (as fallback solution):
        std::ostringstream ostr;
        ostr << "prg-" << ::getpid();
        result= ostr.str();
    }
    return result;
} // eo get_program_name



void _cleanup()
{
    // Note: Locking is done in close_syslog();
    close_syslog();
    //TODO other cleanups?
} // _cleanup


class __Initializer
{
    public:
        __Initializer()
        {
            std::atexit( _cleanup );
        }
} __initialize;


} // eo namespace <anonymous>



/*
** implementation of Facility
*/


const int Facility::AuthPriv= LOG_AUTH;
const int Facility::Cron    = LOG_CRON;
const int Facility::Daemon  = LOG_DAEMON;
const int Facility::Kern    = LOG_KERN;
const int Facility::Mail    = LOG_MAIL;
const int Facility::News    = LOG_NEWS;
const int Facility::Syslog  = LOG_SYSLOG;
const int Facility::User    = LOG_USER;
const int Facility::UUCP    = LOG_UUCP;
const int Facility::Local0  = LOG_LOCAL0;
const int Facility::Local1  = LOG_LOCAL1;
const int Facility::Local2  = LOG_LOCAL2;
const int Facility::Local3  = LOG_LOCAL3;
const int Facility::Local4  = LOG_LOCAL4;
const int Facility::Local5  = LOG_LOCAL5;
const int Facility::Local6  = LOG_LOCAL6;
const int Facility::Local7  = LOG_LOCAL7;



/*
** implementation of PartLogger::LogHelper
*/

PartLogger::LogHelper::LogHelper(PartLogger& logger, int level, const SourceLocation& loc)
: Logger(logger)
, Level(level)
, Location(loc)
{
    StreamPtr.reset(new std::ostringstream());
} // eo PartLogger::LogHelper::LogHelper(PartLogger&,int)

PartLogger::LogHelper::LogHelper(const LogHelper& helper)
: Logger(helper.Logger)
, Level(helper.Level)
, Location(helper.Location)
, StreamPtr(helper.StreamPtr)
{
} // eo PartLogger::LogHelper::LogHelper(const LogHelper&)


PartLogger::LogHelper::~LogHelper()
{
    if (StreamPtr.get())
    {
        if (Location)
        {
            //*m_stream_ptr << "  at " << m_loc.Line << " in " << m_loc.FunctionName;
            *StreamPtr << " @" << Location.get_location_tag();
        }
        std::string msg(StreamPtr->str());
        if (!msg.empty())
        {
            Logger.log(Level,msg);
        }
    }
} // eo PartLogger::LogHelper::~LogHelper


/*
** implementation of PartLogger
*/

/**
 * constructor for a part logger.
 * @param part name of the part (module name) using the logger instance.
 */
PartLogger::PartLogger(const std::string& part)
: Part(part)
{
} // eo PartLogger::PartLogger(const std.:string&)


/**
 * @brief constructor for a part logger at module level.
 * @param loc the source location where the PartLogger is constructed.
 *
 * The part name is derived from the filename given with the source location by
 * using the basename and cutting off the C++ file suffix (if it is a well known one;
 * currently known extensions: cpp, cxx, c++, cc, C).
 */
PartLogger::PartLogger( const SourceLocation& loc )
{
    if (loc.Line>0 && ! loc.File.empty())
    {
        std::string str= basename(loc.File);
        Part= remove_suffix(str,".cpp");
        if (Part == str) Part= remove_suffix(str,".cxx");
        if (Part == str) Part= remove_suffix(str,".c++");
        if (Part == str) Part= remove_suffix(str,".cc");
        if (Part == str) Part= remove_suffix(str,".C");
    }
    else
    {
        Part="Unknown";
    }
}// PartLogger::PartLogger(const SourceLocation&)


PartLogger::~PartLogger()
{
}


/**
 * generic log function.
 * @param level the log level.
 * @param msg the log message.
 */
void PartLogger::log(int level, const std::string msg)
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (level <= g_max_level)
    {
        log_part_msg(level, Part, msg);
    }
} // eo PartLogger::log(int,const std::string);


void PartLogger::fatal(const std::string& msg)
{
    log(LOG_EMERG,msg);
} // eo PartLogger::fatal(const std::string&)


void PartLogger::alert(const std::string& msg)
{
    log(LOG_ALERT,msg);
} // eo PartLogger::alert(const std::string&)


void PartLogger::critical(const std::string& msg)
{
    log(LOG_CRIT,msg);
} // eo PartLogger::critical(const std::string&)


void PartLogger::error(const std::string& msg)
{
    log(LOG_ERR, msg);
} // eo PartLogger::error(const std::string&)


void PartLogger::warning(const std::string& msg)
{
    log(LOG_WARNING, msg);
} // eo PartLogger::warning(const std::string&)


void PartLogger::notice(const std::string& msg)
{
    log(LOG_NOTICE, msg);
} // eo PartLogger::notice(const std::string&)


void PartLogger::info(const std::string& msg)
{
    log(LOG_INFO, msg);
} // eo PartLogger::info(const std::string&)


void PartLogger::debug(const std::string& msg)
{
    log(LOG_DEBUG, msg);
} // eo PartLogger::debug(const std::string&)



PartLogger::LogHelper PartLogger::fatal(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_EMERG,loc);
} // eo PartLogger::fatal(const SourceLocation&)


PartLogger::LogHelper PartLogger::alert(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_ALERT,loc);
} // eo PartLogger::alert(const SourceLocation&)


PartLogger::LogHelper PartLogger::critical(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_CRIT,loc);
} // eo PartLogger::critical(const SourceLocation&)


PartLogger::LogHelper PartLogger::error(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_ERR,loc);
} // eo PartLogger::error(const SourceLocation&)


PartLogger::LogHelper PartLogger::warning(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_WARNING,loc);
} // eo PartLogger::warning(const SourceLocation&)


PartLogger::LogHelper PartLogger::notice(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_NOTICE,loc);
} // eo PartLogger::notice(const SourceLocation&)


PartLogger::LogHelper PartLogger::info(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_INFO,loc);
} // eo PartLogger::info(const SourceLocation&)


PartLogger::LogHelper PartLogger::debug(const SourceLocation& loc)
{
    return PartLogger::LogHelper(*this,LOG_DEBUG,loc);
} // eo PartLogger::debug(const SourceLocation&)

/*
**
*/


/**
 * enable logging to syslog with a name and a facility.
 * @param name the name used as ident.
 * @param facility the facility which should be used.
 */
void enable_syslog( const std::string& name, Facility facility )
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    close_syslog();
    g_ident= name;
    g_facility= facility;
    open_syslog();
} // eo enable_syslog(const std::string,Facility)


/**
 * enable logging to syslog with a facility.
 * The ident is used from a previous call or (if none was set) is
 * determined by reading the program path from /proc/\<pid\>/exe.
 * @param facility the facility which should be used.
 */
void enable_syslog( Facility facility )
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (g_ident.empty())
    {
        g_ident= get_program_name();
    }
    close_syslog();
    g_facility = facility;
    open_syslog();
} // eo enable_syslog(Facility)


/**
 * enable or disable logging to syslog.
 * @param enable whether the logging to syslog should be enabled or not.
 */
void enable_syslog( bool enable )
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (enable)
    {
        if (!g_syslog_opened)
        {
            enable_syslog( g_facility );
        }
    }
    else // ! enable
    {
        close_syslog();
    }
} // eo enable_syslog(bool)


/**
 * enable/ disable loggin to stderr.
 * @param enable whether to enable or disable logging to stderr.
 */
void enable_stderr_log(bool enable)
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    g_stderr_log= enable;
} // eo enableStderr;



/**
 * enable logging to a file.
 * @param name path to the file.
 *
 * @note only one log file can be use at a time.
 */
void enable_log_file( const std::string& name )
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    g_log_file_name= name;
    g_log_stream_ptr.reset( new std::ofstream() );
    g_log_stream_ptr->open( name.c_str(), std::ios::out|std::ios::app );
    //std::cerr << "### opened \"" << name << "\"" << g_log_stream_ptr->good() << std::endl;
} // eo enable_log_file(const std::string&)


/**
 * enable or disable loggin to a file.
 * if a logfile was already set by a previous call to enable_log_file(const std::string&)
 * that one is used; else it logs to <tt>/var/log/</tt><em>program name</em><tt>.log</tt>.
 * @param enable whether to enable or disable logging to a file.
 */
void enable_log_file( bool enable )
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (enable)
    {
        if (g_log_file_name.empty())
        {
            std::ostringstream ostr;
            ostr << "/var/log/" << get_program_name() << ".log";
            enable_log_file( ostr.str() );
        }
        else
        {
            enable_log_file( g_log_file_name );
        }
    }
    else // ! enable
    {
        g_log_stream_ptr.reset();
    }
} // eo enable_log_file(bool)


/**
 * @brief returns if loging to file is enabled and active.
 * @return @a true if logfile is enabled and opened.
 */
bool is_logging_to_file()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    return g_log_stream_ptr and g_log_stream_ptr->good();
} // eo is_logging_to_file()



/**
 * @brief returns the current name of the log file.
 * @return the name of the log file; empty if none was given.
 *
 * This function returns the last used log file name; even
 * when logging to that file is currently disabled.
 */
std::string get_log_file_name()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    return g_log_file_name;
} // eo get_log_file_name()


/**
 * @brief re-opens the logfiles (if applicable).
 */
void reopen()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    if (g_log_stream_ptr)
    {
        enable_log_file(false); // closes log, but holds the name.
        enable_log_file(true);  // opens the log file again.
    }
} // eo reopen()


/**
 * set a new log level.
 * @param level the new log level.
 * @return the previous log level.
 */
int set_log_level(int level)
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    int previous = g_max_level;

    // Sanity check
    if (level < LogLevel::Emergency)
      level = LogLevel::Emergency;
    else if (level > LogLevel::Debug)
      level = LogLevel::Debug;

    g_max_level = level;

    return previous;
} // eo set_log_level(int)


/**
 * returns the current log level.
 * @return the current log level.
 */
int get_log_level()
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    return g_max_level;
} // eo get_log_level()


/**
 * returns if the current log level covers the given level.
 * This is a convenience function for optimization of log output (especially debug output).
 * @param level the level which should be tested for.
 * @return @a true iff a message with the level would be written out.
 */
bool has_log_level(int level)
{
    boost::recursive_mutex::scoped_lock lock(LoggerLock);

    return (g_max_level >= level);
} // eo has_log_level(int)



} // eo namespace Logger
} // eo namespace I2n