2
\$\begingroup\$

I wrote a Logger which uses the destruction of temporary objects to Log their values including a scope time logger. Lets see what i can improve here to increase the performance and everything else.

class Logger
 {
 public:
     static inline LogMessage Log(LoggerTypes type, const std::string& file,
                                  const int& i);


     /**
     \brief Get a Timer Message to mesure the time of a scope

     Returns a Timer message which can be shifted ostream to with <<.
     The Message will be written to consol and log.

     The message will automatically append the time since creation and leaving
     the local scope. So if use without the macro create a local variable for it.
     \code
     {//start a scope
         LogTimer t = Logger::Timer(__FILE__,__LINE__);
         //do some thing wou want to mesure the time of
     } //here it well be logged automatically!
     \endcode
     */
     static inline LogTimer Timer(const std::string& file, const int& i);

     static inline Logger& getInstance();
     static void setLogFile(const std::string& filename);

     void setLogLevel(const int& i);
     int getLogLevel() const;

     void inline operator<<(const std::ostringstream& message) const;

 private:
     Logger() : m_logLevel(DEBUG) { };

     ~Logger();
     Logger(const Logger&) = delete;
     Logger& operator=(const Logger& other) = delete;

     static std::ofstream* m_file;
     static Logger m_instance;
     static tasking::SpinLock m_lock;
     int m_logLevel;
 };
//.cpp
std::ofstream* Logger::m_file = nullptr;
Logger Logger::m_instance;
tasking::SpinLock Logger::m_lock;

void Logger::setLogLevel(const int& i)
{
    m_logLevel = i;
}

int Logger::getLogLevel() const
{
    return m_logLevel;
}

void Logger::setLogFile(const std::string& filename)
{
    if (m_file != nullptr)
    {
        m_file->flush();
        delete m_file;
    }
    m_file = new std::ofstream(filename, std::ios::out | std::ios::app);
}

Logger::~Logger()
{
    //clean up
    if(m_file != nullptr)
        m_file->flush();
    delete m_file;
}
//.hpp
inline LogMessage Logger::Log(LoggerTypes type, const std::string& file, const int& i)
{
    return LogMessage(type, file, i);
}

inline LogTimer Logger::Timer(const std::string& file, const int& i)
{
    return LogTimer(TIMER, file, i);
}

inline Logger& Logger::getInstance()
{
    if (m_file == nullptr)
        //use a fixed name so it can always be used!
        setLogFile("startup.log");
    return m_instance;
}

inline void Logger::operator<<(const std::ostringstream& message) const
{
    std::lock_guard<tasking::SpinLock> lock(m_lock);
    std::cout << message.str() << "\n";
    if (m_file != nullptr)
    {
        *m_file << message.str() << "\n";
        m_file->flush();
    }
}

And a Basic Log Message:

enum LoggerTypes
{
    ERROR_L = 0,
    EXCAPTION = 1,
    WARNING = 2,
    TIMER = 3,
    INFO = 4,
    DEBUG = 5,
    SIZE_OF_ENUM_LOGGER_TYPES
};

struct LoggerTypeMap
{
    static const char* EnumString[];
    /**
    @return the configValue as const char*
    */
    static std::string get(const LoggerTypes& e);
};

class LogMessage
{
public:
    explicit inline LogMessage(const LoggerTypes& type, const std::string& file = "",
                               const int& i = 0);
    ~LogMessage();
    std::string currentDateTime() const;
    /**
    returns self reference
    */
    template <typename T>
    inline LogMessage& operator<<(const T& m);

    LogMessage(const LogMessage& other);
    LogMessage(LogMessage&& other);

    LogMessage& operator=(const LogMessage& other);
    LogMessage& operator=(LogMessage&& other);

private:
    std::ostringstream m_stream;
    LoggerTypes m_type;
};

const char* LoggerTypeMap::EnumString[] =
{
    "error",
    "excaption",
    "warn",
    "timer",
    "info",
    "debug"
};
//check if valid numer must be the size of the enum!
static_assert(sizeof(LoggerTypeMap::EnumString) / sizeof(char*) == SIZE_OF_ENUM_LOGGER_TYPES, "size dont match!");

std::string LoggerTypeMap::get(const LoggerTypes& e)
{
    return EnumString[e]; //implicit convention and move
}


LogMessage::~LogMessage()
{
    //push the message at the end
    if (Logger::getInstance().getLogLevel() >= m_type)
        Logger::getInstance() << m_stream;
}

// Get current date/time, format is YYYY-MM-DD.HH:mm:ss
std::string LogMessage::currentDateTime() const
{
    auto now = time(nullptr);
    struct tm tstruct;
    char buf[80];
    tstruct = *localtime(&now);
    strftime(buf, sizeof(buf), "[%d-%m-%Y][%X]", &tstruct);
    return buf;
}

LogMessage::LogMessage(const LogMessage& other) : m_type(other.m_type)
{
    m_stream << other.m_stream.str();
}

LogMessage::LogMessage(LogMessage&& other) : m_stream(std::move(other.m_stream)), m_type(other.m_type) {}

LogMessage& LogMessage::operator=(const LogMessage& other)
{
    if (this == &other)
        return *this;
    m_stream << other.m_stream.str();
    m_type = other.m_type;
    return *this;
}

LogMessage& LogMessage::operator=(LogMessage&& other)
{
    if (this == &other)
        return *this;
    m_stream = std::move(other.m_stream);
    m_type = other.m_type;
    return *this;
}

template <typename T>
inline LogMessage& LogMessage::operator<<(const T& m)
{
    m_stream << m;
    return *this;

}
template <>
inline LogMessage& LogMessage::operator<<(const bool& b)
{
    if (b)
        m_stream << "true";
    else
        m_stream << "false";
    return *this;
}

inline LogMessage::LogMessage(const LoggerTypes& type, const std::string& file,
                              const int& i) : m_stream(), m_type(type)
{
    //build the logstring
    m_stream << "[" + LoggerTypeMap::get(type) + "][File:" + file + "][Line:" +
             std::to_string(i) + "][thread:" << std::this_thread::get_id() <<
             "]" + currentDateTime() + " ";
}

And the Scopetimer:

class LogTimer : public LogMessage
{
public:

    explicit inline LogTimer(const LoggerTypes& type, const std::string& file = "",
                      const int& i = 0);
    ~LogTimer();

    template <typename T>
    LogTimer& operator<<(const T& m);

    LogTimer(const LogTimer& other);
    LogTimer(LogTimer&& other);

    inline LogTimer& operator=(const LogTimer& other);
    inline LogTimer& operator=(LogTimer&& other);
private:
    std::chrono::high_resolution_clock::time_point m_start;
};
LogTimer::LogTimer(const LoggerTypes& type, const std::string& file,
                   const int& i) : LogMessage(type, file, i),
    m_start(std::chrono::high_resolution_clock::now()) {}

template <typename T>
LogTimer& LogTimer::operator<<(const T& m)
{
    LogMessage::operator<<(m);
    return *this;
}


inline LogTimer::LogTimer(const LogTimer& other) : LogMessage(other), m_start(other.m_start) { }

inline LogTimer::LogTimer(LogTimer&& other) : LogMessage(std::move(other)), m_start(std::move(other.m_start)) { }

inline LogTimer& LogTimer::operator=(const LogTimer& other)
{
    if (this == &other)
        return *this;
    LogMessage::operator =(other);
    m_start = other.m_start;
    return *this;
}


inline LogTimer& LogTimer::operator=(LogTimer&& other)
{
    if (this == &other)
        return *this;
    LogMessage::operator =(std::move(other));
    m_start = std::move(other.m_start);
    return *this;
}

Macros:

#define __FILENAME__ (strrchr(__FILE__, '\\') ? strrchr(__FILE__, '\\') + 1 : __FILE__)

#define LOG_ERROR jimdb::common::Logger::Log(jimdb::common::LoggerTypes::ERROR_L,__FILENAME__,__LINE__)
#define LOG_INFO jimdb::common::Logger::Log(jimdb::common::LoggerTypes::INFO,__FILENAME__,__LINE__)
#define LOG_WARN jimdb::common::Logger::Log(jimdb::common::LoggerTypes::WARNING,__FILENAME__,__LINE__)
#define LOG_EXCAPT jimdb::common::Logger::Log(jimdb::common::LoggerTypes::EXCAPTION,__FILENAME__,__LINE__)
#define LOG_DEBUG jimdb::common::Logger::Log(jimdb::common::LoggerTypes::DEBUG,__FILENAME__,__LINE__)
#define LOG_SCOPE_TIME jimdb::common::LogTimer t___ = jimdb::common::Logger::Timer(__FILENAME__,__LINE__); t___

Sample usage:

int main(){
    LOG_DEBUG << "some Debug Logentry";
    {
        LOG_SCOPE_TIME << "Some Random Scope"
        for(auto i = 0; i < 10000; ++i)
           LOG_INFO << i;
    }
}

Some real Sample outputs:

[warn][File:handshake.cpp][Line:20][thread:10796][01-11-2015][13:29:49] handshake Failed
[debug][File:clienthandle.cpp][Line:42][thread:10796][01-11-2015][13:29:49] Client:228 closed
[warn][File:handshake.cpp][Line:20][thread:11924][01-11-2015][13:29:49] handshake Failed
\$\endgroup\$
  • \$\begingroup\$ You have fallen into the common trap of people trying to implement logging. If I have log level set for on;y critical events then I don't want the logging software to spend time building a message for lower logging levels. Currently you always build the log message even if it is thrown away. \$\endgroup\$ – Martin York Nov 12 '15 at 12:09
  • \$\begingroup\$ Debug logging can get quite verbose and dense. If I am no longer debugging the code then building all the debug messages will put a high overhead on normal operations. When I release the code to customers I want the overhead of debug logging to be near zero unless I explicitly turn it on in the config file. \$\endgroup\$ – Martin York Nov 12 '15 at 12:13
  • \$\begingroup\$ True i still miss the outline of debug messages when release compiling. Didn't notice that. But that should be possible to add. Somehow I hope since it does work nice I think. You can add this as bonus if you like and know how to \$\endgroup\$ – BennX Nov 12 '15 at 20:41
  • \$\begingroup\$ You still need to generate Debug Messages in a release build. This should be controlled by a configuration file. But if the current configuration is set for only Critical events then you should not waste time building a message (that is computationally expensive to do) when it is just going to be throw away. \$\endgroup\$ – Martin York Nov 13 '15 at 0:36

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.