Easylogging++入门教程（五）Easylogging++ 特征

上一篇：Easylogging++入门教程（四）Easylogging++ 日志记录

Easylogging++ is feature-rich logging library. Apart from features already mentioned above, here are some extra features. If code snippets don’t make sense and further sample is needed, there are many samples available at github repository (samples). Feel free to browse around.

Performance Tracking

One of the most notable features of Easylogging++ is its ability to track performance of your function or block of function. Please note, this is not backward compatible as previously we had macros that user must had defined in order to track performance and I am sure many users had avoided in doing so. (Read v8.91 ReadMe for older way of doing it) The new way of tracking performance is much easier and reliable. All you need to do is use one of two macros from where you want to start tracking.

• TIMED_FUNC(obj-name)
• TIMED_SCOPE(obj-name, block-name)
• TIMED_BLOCK(obj-name, block-name)

An example that just uses usleep

void performHeavyTask(int iter) {
   TIMED_FUNC(timerObj);
   // Some initializations
   // Some more heavy tasks
   usleep(5000);
   while (iter-- > 0) {
       TIMED_SCOPE(timerBlkObj, "heavy-iter");
       // Perform some heavy task in each iter
       usleep(10000);
   }
}

The result of above execution for iter = 10, is as following

06:22:31,368 INFO Executed [heavy-iter] in [10 ms]
06:22:31,379 INFO Executed [heavy-iter] in [10 ms]
06:22:31,389 INFO Executed [heavy-iter] in [10 ms]
06:22:31,399 INFO Executed [heavy-iter] in [10 ms]
06:22:31,409 INFO Executed [heavy-iter] in [10 ms]
06:22:31,419 INFO Executed [heavy-iter] in [10 ms]
06:22:31,429 INFO Executed [heavy-iter] in [10 ms]
06:22:31,440 INFO Executed [heavy-iter] in [10 ms]
06:22:31,450 INFO Executed [heavy-iter] in [10 ms]
06:22:31,460 INFO Executed [heavy-iter] in [10 ms]
06:22:31,460 INFO Executed [void performHeavyTask(int)] in [106 ms]

In the above example, we have used both the macros. In line-2 we have TIMED_FUNC with object name timerObj and line-7 we have TIMED_SCOPE with object name timerBlkObj and block name heavy-iter. Notice how block name is thrown out to the logs with every hit. (Note: TIMED_FUNC is TIMED_BLOC with block name = function name)

You might wonder why do we need object name. Well easylogging++ performance tracking feature takes it further and provides ability to add, what’s called checkpoints. Checkpoints have two macros:

• PERFORMANCE_CHECKPOINT(timed-block-obj-name)
• PERFORMANCE_CHECKPOINT_WITH_ID(timed-block-obj-name, id)

Take a look at following example

void performHeavyTask(int iter) {
   TIMED_FUNC(timerObj);
   // Some initializations
   // Some more heavy tasks
   usleep(5000);
   while (iter-- > 0) {
       TIMED_SCOPE(timerBlkObj, "heavy-iter");
       // Perform some heavy task in each iter
       // Notice following sleep varies with each iter
       usleep(iter * 1000);
       if (iter % 3) {
           PERFORMANCE_CHECKPOINT(timerBlkObj);
       }
   }
}

Notice macro on line-11 (also note comment on line-8. It’s checkpoint for heavy-iter block. Now notice following output

06:33:07,558 INFO Executed [heavy-iter] in [9 ms]
06:33:07,566 INFO Performance checkpoint for block [heavy-iter] : [8 ms]
06:33:07,566 INFO Executed [heavy-iter] in [8 ms]
06:33:07,573 INFO Performance checkpoint for block [heavy-iter] : [7 ms]
06:33:07,573 INFO Executed [heavy-iter] in [7 ms]
06:33:07,579 INFO Executed [heavy-iter] in [6 ms]
06:33:07,584 INFO Performance checkpoint for block [heavy-iter] : [5 ms]
06:33:07,584 INFO Executed [heavy-iter] in [5 ms]
06:33:07,589 INFO Performance checkpoint for block [heavy-iter] : [4 ms]
06:33:07,589 INFO Executed [heavy-iter] in [4 ms]
06:33:07,592 INFO Executed [heavy-iter] in [3 ms]
06:33:07,594 INFO Performance checkpoint for block [heavy-iter] : [2 ms]
06:33:07,594 INFO Executed [heavy-iter] in [2 ms]
06:33:07,595 INFO Performance checkpoint for block [heavy-iter] : [1 ms]
06:33:07,595 INFO Executed [heavy-iter] in [1 ms]
06:33:07,595 INFO Executed [heavy-iter] in [0 ms]
06:33:07,595 INFO Executed [void performHeavyTask(int)] in [51 ms]

You can also compare two checkpoints if they are in sub-blocks e.g, changing from PERFORMANCE_CHECKPOINT(timerBlkObj) toPERFORMANCE_CHECKPOINT(timerObj) will result in following output

06:40:35,522 INFO Performance checkpoint for block [void performHeavyTask(int)] : [51 ms ([1 ms] from last checkpoint)]

If you had used PERFORMANCE_CHECKPOINT_WITH_ID(timerObj, "mychkpnt"); instead, you will get

06:44:37,979 INFO Performance checkpoint [mychkpnt] for block [void performHeavyTask(int)] : [51 ms ([1 ms] from checkpoint 'mychkpnt')]

Following are some useful macros that you can define to change the behaviour

Notes:

1. Performance tracking uses performance logger (INFO level) by default unless el::base::PerformanceTracker is constructed manually (not using macro – not recommended). When configuring other loggers, make sure you configure this one as well.
2. In above examples, timerObj and timerBlkObj is of type el::base::PerformanceTracker and checkpoint() can be accessed by timerObj.checkpoint() but not recommended as this will override behaviour of using macros, behaviour like location of checkpoint.
3. In order to access el::base::PerformanceTracker while in TIMED_BLOCK, you can use timerObj.timer
4. TIMED_BLOCK macro resolves to a single-looped for-loop, so be careful where you define TIMED_BLOCK, if for-loop is allowed in the line where you use it, you should have no errors.
   

   You may be interested in python script to parse performance logs

   Goto Top

Make Use of Performance Tracking Data

If you wish to capture performance tracking data right after it is finished, you can do so by extendingel::PerformanceTrackingCallback.

In order to install this handler, use void Helpers::installPerformanceTrackingCallback<T>(const std::string& id). Where Tis type of your handler. If you wish to uninstall a callback, you can do so by usingHelpers::uninstallPerformanceTrackingCallback<T>(const std::string& id). See samples for details

DO NOT TRACK PERFORMANCE IN THIS HANDLER OR YOU WILL END UP IN INFINITE-LOOP

Goto Top

Log File Rolling

Easylogging++ has ability to roll out (or throw away) log files if they reach certain limit. You can configure this by settingMax_Log_File_Size. See Configuration section above.

If you are having failure in log-rollout, you may have failed to add flag i.e, el::LoggingFlags::StrictLogFileSizeCheck.

This feature has it’s own section in this reference manual because you can do stuffs with the file being thrown away. This is useful, for example if you wish to back this file up etc. This can be done by usingel::Helpers::installPreRollOutCallback(const PreRollOutCallback& handler) where PreRollOutCallback is typedef of typestd::function<void(const char*, std::size_t)>. Please note following if you are using this feature

You should not log anything in this function. This is because logger would already be locked in multi-threaded application and you can run into dead lock conditions. If you are sure that you are not going to log to same file and not using same logger, feel free to give it a try.

Goto Top

Crash Handling

Easylogging++ provides ability to handle unexpected crashes for GCC compilers. This is active by default and can be disabled by defining macro ELPP_DISABLE_DEFAULT_CRASH_HANDLING. By doing so you are telling library not to handle any crashes. Later on if you wish to handle crash yourself, you can assign crash handler of type void func(int) where int is signal caught.

Following signals are handled;

• SIGABRT (If ELPP_HANDLE_SIGABRT macro is defined)
• SIGFPE
• SIGILL
• SIGSEGV
• SIGINT

Stacktraces are not printed by default, in order to do so define macro ELPP_STACKTRACE_ON_CRASH. Remember, stack trace is only available for GCC compiler.

Default handler and stack trace uses default logger.

Following are some useful macros that you can define to change the behaviour

Goto Top

Installing Custom Crash Handlers

You can use your own crash handler by using el::Helpers::setCrashHandler(const el::base::debug::CrashHandler::Handler&);.

Make sure to abort application at the end of your crash handler using el::Helpers::crashAbort(int). If you fail to do so, you will get into endless loop of crashes.

Here is a good example of your own handler

#include "easylogging++.h"

INITIALIZE_EASYLOGGINGPP

void myCrashHandler(int sig) {
    LOG(ERROR) << "Woops! Crashed!";     
    // FOLLOWING LINE IS ABSOLUTELY NEEDED AT THE END IN ORDER TO ABORT APPLICATION
    el::Helpers::crashAbort(sig);
}
int main(void) {
    el::Helpers::setCrashHandler(myCrashHandler);

    LOG(INFO) << "My crash handler!";

    int* i;
    *i = 0; // Crash!

    return 0;
}

If you wish to log reason for crash you can do so by using el::Helpers::logCrashReason(int, bool, const el::Level&, const char*). Following are default parameters for this function:

 bool stackTraceIfAvailable = false
 const el::Level& level = el::Level::Fatal
 const char* logger = "default"

Goto Top

Stacktrace

Easylogging++ supports stack trace printing for GCC compilers. You can print stack trace at anytime by callingel::base::debug::StackTrace(), formatting will be done automatically. Note, if you are using non-GCC compiler, you will end-up getting empty output.

Goto Top

Multi-threading

Easylogging++ is thread-safe. By default thread-safety is disabled. You can enable it by defining ELPP_THREAD_SAFE otherwise you will see unexpected results. This is intentional to make library efficient for single threaded application.

Goto Top

CHECK Macros

Easylogging++ supports CHECK macros, with these macros you can quickly check whether certain condition fulfills or not. If not Easylogging++ writes FATAL log, causing application to stop (unless defined macro to prevent stopping application on fatal).

Same versions of macros are available for DEBUG only mode, these macros start with D (for debug) followed by the same name. e.g, DCHECK to check only in debug mode (i.e, when _DEBUG is defined or NDEBUG is undefined)

Goto Top

Logging perror()

Easylogging++ supports perror() styled logging using PLOG(LEVEL), PLOG_IF(Condition, LEVEL), and PCHECK() usingdefault logger; and for custom logger use CPLOG(LEVEL, LoggerId), CPLOG_IF(Condition, LEVEL, LoggerId). This will append : log-error [errno] in the end of log line.

Goto Top

Syslog

Easylogging++ supports syslog for platforms that have syslog.h header. In order to enable it, you need to defineELPP_SYSLOG. If your platform does not have syslog.h, make sure you do not define this macro or you will end up in errors. Once you are ready to use syslog, you can do so by using one of SYSLOG(LEVEL), SYSLOG_IF(Condition, LEVEL),SYSLOG_EVERY_N(n, LEVEL) and uses logger ID: syslog. If you want to use custom logger you can do so by usingCSYSLOG(LEVEL, loggerId) or CSYSLOG_IF(Condition, LEVEL, loggerId) or CSYSLOG_EVERY_N(n, LEVEL, loggerId)

Syslog in Easylogging++ supports C++ styled streams logging, following example;

#include "easylogging++.h"

INITIALIZE_EASYLOGGINGPP
int main(void) {
    ELPP_INITIALIZE_SYSLOG("my_proc", LOG_PID | LOG_CONS | LOG_PERROR, LOG_USER) // This is optional, you may not add it if you dont want to specify options
    // Alternatively you may do
    // el::SysLogInitializer elSyslogInit("my_proc", LOG_PID | LOG_CONS | LOG_PERROR, LOG_USER);
    SYSLOG(INFO) << "This is syslog - read it from /var/log/syslog"
    return 0;
}

Syslog support for Easylogging++ only supports following levels; each level is corresponded with syslog priority as following

• INFO (LOG_INFO)
• DEBUG (LOG_DEBUG)
• WARNING (LOG_WARNING)
• ERROR (LOG_ERR)
• FATAL (LOG_EMERG)

Following levels are not supported and correspond to LOG_NOTICE: TRACE, whereas VERBOSE level is completely not supported

Goto Top

Qt Logging

Easylogging++ has complete logging support for Qt core library. define ELPP_QT_LOGGING macro. This will include all the headers supported Qt logging. Once you did that, you should be good to go.

Following Qt classes and containers are supported by Easylogging++ v9.0+

Similar to STL logging, Qt containers are also limit to log 100 entries per log, you can change this behaviour by changing base::consts::kMaxLogPerContainer from header but this is not recommended as this was done for performance purposes.

Also note, if you are logging a container that contains custom class, make sure you have read Extending Library section below.

Goto Top

Boost Logging

Easylogging++ supports some of boost templates. In order to enable boost logging, define macro ELPP_BOOST_LOGGING

Following table shows the templates supported.

Goto Top

wxWidgets Logging

Easylogging++ supports some of wxWidgets templates. In order to enable wxWidgets logging, define macroELPP_WXWIDGETS_LOGGING

Following table shows the templates supported.

wxWidgets has its own way of declaring and defining some templates e.g, wxList where you use WX_DECLARE_LIST macro to declare a list.

In order to setup a container for logging that holds pointers to object, use ELPP_WX_PTR_ENABLED, otherwise if container holds actual object e.g, wxHashSet use ELPP_WX_ENABLED. For containers like wxHashMap because it contains value and pair, useELPP_WX_HASH_MAP_ENABLED macro.

// wxList example
WX_DECLARE_LIST(int, MyList);
WX_DEFINE_LIST(MyList);
// Following line does the trick
ELPP_WX_PTR_ENABLED(MyList);

// wxHashSet example
WX_DECLARE_HASH_SET(int, wxIntegerHash, wxIntegerEqual, IntHashSet);
// Following line does the trick!
ELPP_WX_ENABLED(IntHashSet)

// wxHashMap example
WX_DECLARE_STRING_HASH_MAP(wxString, MyHashMap);
// Following line does the trick
ELPP_WX_HASH_MAP_ENABLED(MyHashMap)

You may also have a look at wxWidgets sample

Goto Top

Extending Library

Logging Your Own Class

You can log your own classes by extending el::Loggable class and implementing pure-virtual function void log(std::ostream& os) const. Following example shows a good way to extend a class.

#include "easylogging++.h"

INITIALIZE_EASYLOGGINGPP
class Integer : public el::Loggable {
public:
    Integer(int i) : m_underlyingInt(i) {
    }
    Integer& operator=(const Integer& integer) {
        m_underlyingInt = integer.m_underlyingInt;
        return *this;
    }
    // Following line does the trick!
    // Note: el::base::type::ostream_t is either std::wostream or std::ostream depending on unicode enabled or not
    virtual void log(el::base::type::ostream_t& os) const {
        os << m_underlyingInt;
    }
private:
    int m_underlyingInt;
};

int main(void) {
    Integer count = 5;
    LOG(INFO) << count;
    return 0;
}

Goto Top

Logging Third-party Class

Let’s say you have third-party class that you don’t have access to make changes to, and it’s not yet loggable. In order to make it loggable, you can use MAKE_LOGGABLE(ClassType, ClassInstance, OutputStreamInstance) to make it Easylogging++ friendly.

Following sample shows a good usage:

#include "easylogging++.h"

INITIALIZE_EASYLOGGINGPP

class Integer {
public:
    Integer(int i) : m_underlyingInt(i) {
    }
    Integer& operator=(const Integer& integer) {
        m_underlyingInt = integer.m_underlyingInt;
        return *this;
    }
    int getInt(void) const { return m_underlyingInt; }
private:
    int m_underlyingInt;
};

// Following line does the trick!
inline MAKE_LOGGABLE(Integer, integer, os) {
    os << integer.getInt();
    return os;
}
int main(void) {
    Integer count = 5;
    LOG(INFO) << count;
    return 0;
}

Another very nice example (to log std::chrono::system_clock::time_point)

inline MAKE_LOGGABLE(std::chrono::system_clock::time_point, when, os) {
    time_t t = std::chrono::system_clock::to_time_t(when);
    auto tm = std::localtime(&t);
    char buf[1024];
    strftime(buf,sizeof(buf), "%F %T (%Z)", tm);
    os << buf;
    return os;
}

This may not be practically best implementation but you get the point.

Just be careful with this as having a time-consuming overloading of log(el::base::type::ostream_t& os) andMAKE_LOGGABLE, they get called everytime class is being logged.

Goto Top

Manually Flushing and Rolling Log Files

You can manually flush log files using el::Logger::flush() (to flush single logger with all referencing log files) orel::Loggers::flushAll() (to flush all log files for all levels).

If you have not set flag LoggingFlag::StrictLogFileSizeCheck for some reason, you can manually check for log files that need rolling; by using el::Helpers::validateFileRolling(el::Logger*, const el::Level&).

Goto Top

Log Dispatch Callback

If you wish to capture log message right after it is dispatched, you can do so by having a class that extendsel::LogDispatchCallback and implement the pure-virtual functions, then install it at anytime usingel::Helpers::installLogDispatchCallback<T>(const std::string&). If you wish to uninstall a pre-installed handler with same ID, you can do so by using el::Helpers::uninstallLogDispatchCallback<T>(const std::string&)

DO NOT LOG ANYTHING IN THIS HANDLER OR YOU WILL END UP IN INFINITE-LOOP

Goto Top

Asynchronous Logging

Asynchronous logging is in experimental stages and they are not widely promoted. You may enable and test this feature by defining macro ELPP_EXPERIMENTAL_ASYNC and if you find some issue with the feature please report in this issue. Reporting issues always help for constant improvements.

Please note:

• Asynchronous will only work with few compilers (it purely uses std::thread)
• Compiler should support std::this_thread::sleep_for. This restriction may (or may not) be removed in future (stable) version of asynchronous logging.
• You should not rely on asynchronous logging in production, this is because feature is in experiemental stages.

上一篇：Easylogging++入门教程（四）Easylogging++ 日志记录