easylogging++的那些事(四)源码分析(七)性能跟踪
在上一篇我们介绍了 VERBOSE 日志信息管理,今天我们开始介绍性能跟踪的实现。
easylogging++的性能跟踪可以分为两种: 代码块整体的跟踪 以及基于代码块整体的跟踪基础上的 代码块内的某个标记点的跟踪 。
在 easylogging++的 功能介绍 中我们介绍过性能跟踪宏的使用:
1、代码块整体的跟踪对应的宏: TIMED_SCOPE_IF
宏、TIMED_SCOPE
宏、TIMED_FUNC_IF
宏、TIMED_FUNC
宏、TIMED_BLOCK
宏。
2、代码块内的某个标记点的跟踪对应的宏:PERFORMANCE_CHECKPOINT
宏、PERFORMANCE_CHECKPOINT_WITH_ID
宏。
我们就从性能跟踪宏开始今天的分析。
宏展开
TIMED_SCOPE_IF 宏
TIMED_SCOPE_IF
宏定义如下:#define TIMED_SCOPE_IF(obj, blockname, condition) el::base::type::PerformanceTrackerPtr obj( condition ? \ new el::base::PerformanceTracker(blockname, ELPP_MIN_UNIT) : nullptr )
用个具体的例子就一目了然了:
TIMED_SCOPE_IF(timerObj, "TIMED_SCOPE_IF", true);
展开后为:
el::base::type::PerformanceTrackerPtr timerObj( true ? new el::base::PerformanceTracker("TIMED_SCOPE_IF", ELPP_MIN_UNIT) : nullptr );
PerformanceTrackerPtr
定义如下:typedef std::unique_ptr<el::base::PerformanceTracker> PerformanceTrackerPtr;
最终展开后的结果就相当于:创建了一个
el::base::PerformanceTracker
类型的独占型智能指针(std::unique_ptr<el::base::PerformanceTracker>
)对象。当这个智能指针对象离开其作用域后,自身就会被销毁,进而自动删除其管理的对象,最终调用el::base::PerformanceTracker
类的析构函数,而这个析构函数执行了真正的性能跟踪统计。
el::base::PerformanceTracker
类后面源码分析的时候回详细说明。
TIMED_SCOPE 宏
TIMED_SCOPE
宏定义如下:#define TIMED_SCOPE(obj, blockname) TIMED_SCOPE_IF(obj, blockname, true)
TIMED_SCOPE_IF
宏前面已经介绍了,这里就不多说了。
TIMED_FUNC_IF 宏
TIMED_FUNC_IF
宏定义如下:#define TIMED_FUNC(obj) TIMED_SCOPE(obj, ELPP_FUNC)
TIMED_SCOPE
宏前面已经介绍了,这里就不多说了。
TIMED_FUNC 宏
TIMED_FUNC
宏定义如下:#define TIMED_FUNC(obj) TIMED_SCOPE(obj, ELPP_FUNC)
TIMED_SCOPE
宏前面已经介绍了,这里就不多说了。
TIMED_BLOCK 宏
TIMED_BLOCK
宏定义如下:#define TIMED_BLOCK(obj, blockName) for (struct { int i; el::base::type::PerformanceTrackerPtr timer; } obj = { 0, \ el::base::type::PerformanceTrackerPtr(new el::base::PerformanceTracker(blockName, ELPP_MIN_UNIT)) }; obj.i < 1; ++obj.i)
从
TIMED_BLOCK
宏定义上来看,这个宏只是定义了for
循环语句的开头部分,循环体空着,真正使用时需要加上循环体才能正常使用。
用个具体的例子就一目了然了:TIMED_BLOCK(timerBlkObj, "TIMED_BLOCK") { //实际要性能测试的代码 }
展开后为:
for (struct { int i; el::base::type::PerformanceTrackerPtr timer; } timerBlkObj = {0, ::base::type::PerformanceTrackerPtr(new el::base::PerformanceTracker("TIMED_BLOCK", ELPP_MIN_UNIT))}; timerBlkObj.i < 1; ++timerBlkObj.i) { }
最终展开后的结果就相当于创建了仅仅执行一次的
for
循环语句,而这个循环语句的循环体内部,创建了一个el::base::PerformanceTracker
类型的独占型智能指针对象。和TIMED_SCOPE_IF
宏一样,这里就不多说了。
PERFORMANCE_CHECKPOINT 宏
PERFORMANCE_CHECKPOINT
宏定义如下:#define PERFORMANCE_CHECKPOINT(obj) obj->checkpoint(std::string(), __FILE__, __LINE__, ELPP_FUNC)
用个具体的例子就一目了然了:
PERFORMANCE_CHECKPOINT(timerObj);
展开后为:
timerObj->checkpoint(std::string(), __FILE__, __LINE__, ELPP_FUNC);
最后展开后的结果相当于调用了某个对象的
checkpoint
接口。
PERFORMANCE_CHECKPOINT_WITH_ID 宏
PERFORMANCE_CHECKPOINT_WITH_ID
宏定义如下:#define PERFORMANCE_CHECKPOINT_WITH_ID(obj, id) obj->checkpoint(id, __FILE__, __LINE__, ELPP_FUNC)
用个具体的例子就一目了然了:
PERFORMANCE_CHECKPOINT_WITH_ID(timerObj, "PERFORMANCE_CHECKPOINT");
展开后为:
timerObj->checkpoint("PERFORMANCE_CHECKPOINT", __FILE__, __LINE__, ELPP_FUNC);
与
PERFORMANCE_CHECKPOINT
宏一样,最后展开后的结果相当于调用了某个对象的checkpoint
接口。
而这个对象的类型实际上就是el::base::PerformanceTracker
类。后面源码分析时我们会清楚的看到这一点。
源码剖析
从上面性能跟踪宏的最终展开结果可以看出来,最终都与 el::base::PerformanceTracker
这个类有关。下面我们就来分析下这个类的实现。
成员变量
std::string m_blockName; // 性能跟踪的代码块的自定义名称
base::TimestampUnit m_timestampUnit; // 性能跟踪的时间精度
std::string m_loggerId; // 性能跟踪对应的日志记录器的ID
bool m_scopedLog; // 开启性能跟踪宏后,默认进行代码块的性能跟踪
Level m_level; // 日志级别
bool m_hasChecked; // 默认为false,进行一次跟踪点统计后置为true
std::string m_lastCheckpointId; // 最近完成性能跟踪点对应的ID
bool m_enabled; // 对应日志记录器的指定日志级别是否启用性能跟踪
struct timeval m_startTime; // 性能跟踪的开始时间
struct timeval m_endTime; // 性能跟踪的结束时间
struct timeval m_lastCheckpointTime; // 最近完成性能跟踪点的时间
成员函数
构造函数
PerformanceTracker::PerformanceTracker(const std::string &blockName, base::TimestampUnit timestampUnit, const std::string &loggerId, bool scopedLog, Level level) : m_blockName(blockName), m_timestampUnit(timestampUnit), m_loggerId(loggerId), m_scopedLog(scopedLog), m_level(level), m_hasChecked(false), m_lastCheckpointId(std::string()), m_enabled(false) { #if !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) && ELPP_LOGGING_ENABLED // We store it locally so that if user happen to change configuration by the end of scope // or before calling checkpoint, we still depend on state of configuration at time of construction // 获取日志记录器对象 el::Logger *loggerPtr = ELPP->registeredLoggers()->get(loggerId, false); // 对应日志记录器的指定日志级别是否启用性能跟踪 m_enabled = loggerPtr != nullptr && loggerPtr->m_typedConfigurations->performanceTracking(m_level); if (m_enabled) { // 启用性能跟踪则记录当前时间为性能跟踪的开始时间 base::utils::DateTime::gettimeofday(&m_startTime); } #endif // !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) && ELPP_LOGGING_ENABLED }
析构函数
析构函数用于执行真正的性能跟踪统计
PerformanceTracker::~PerformanceTracker(void) { #if !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) && ELPP_LOGGING_ENABLED if (m_enabled) { base::threading::ScopedLock scopedLock(lock()); // PerformanceTracker仅仅提供了一个构造函数的实现,其中提供了默认值true,性能跟踪宏使用的是默认值 // 开启性能跟踪宏后,默认进行代码块的性能跟踪 if (m_scopedLog) { // 记录当前时间为性能跟踪的结束时间 base::utils::DateTime::gettimeofday(&m_endTime); // 将时间根据需要调整为合适的格式后,以字符串形式返回 base::type::string_t formattedTime = getFormattedTimeTaken(); // 性能跟踪回调数据对象的初始化,交给性能跟踪回调处理(比如默认DefaultPerformanceTrackingCallback进行性能跟踪的时长统计) // PerformanceTrackingData::DataType::Complete表示当前性能跟踪完成 PerformanceTrackingData data(PerformanceTrackingData::DataType::Complete); data.init(this); data.m_formattedTimeTaken = formattedTime; PerformanceTrackingCallback *callback = nullptr; // 遍历注册的所有性能跟踪回调 for (const std::pair<std::string, base::type::PerformanceTrackingCallbackPtr> &h : ELPP->m_performanceTrackingCallbacks) { callback = h.second.get(); if (callback != nullptr && callback->enabled()) { callback->handle(&data); } } } } #endif // !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) }
在 easylogging++的 主流程 中我们介绍过,日志库初始化的时候,默认会注册
DefaultPerformanceTrackingCallback
。其主要职责就是执行 easylogging++默认的性能跟踪统计。DefaultPerformanceTrackingCallback
的实现稍后会详细分析。checkpoint 接口
checkpoint
接口主要用于跟踪点的性能统计。void PerformanceTracker::checkpoint(const std::string &id, const char *file, base::type::LineNumber line, const char *func) { #if !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) && ELPP_LOGGING_ENABLED // 是否启用性能跟踪 if (m_enabled) { base::threading::ScopedLock scopedLock(lock()); // 记录当前时间为性能跟踪点的结束时间 base::utils::DateTime::gettimeofday(&m_endTime); // 将时间根据需要调整为合适的格式后,以字符串形式返回 base::type::string_t formattedTime = m_hasChecked ? getFormattedTimeTaken(m_lastCheckpointTime) : ELPP_LITERAL(""); // 性能跟踪回调数据对象的初始化,交给性能跟踪回调处理(比如默认DefaultPerformanceTrackingCallback进行性能跟踪的时长统计) // PerformanceTrackingData::DataType::Checkpoint表示单个跟踪点的性能跟踪 PerformanceTrackingData data(PerformanceTrackingData::DataType::Checkpoint); data.init(this); data.m_checkpointId = id; data.m_file = file; data.m_line = line; data.m_func = func; // 经过调整后的时间戳的字符串形式。 data.m_formattedTimeTaken = formattedTime; PerformanceTrackingCallback *callback = nullptr; // 遍历注册的所有性能跟踪回调 for (const std::pair<std::string, base::type::PerformanceTrackingCallbackPtr> &h : ELPP->m_performanceTrackingCallbacks) { callback = h.second.get(); if (callback != nullptr && callback->enabled()) { callback->handle(&data); } } // 更新最后的性能跟踪点的时间为当前跟踪点的结束时间 base::utils::DateTime::gettimeofday(&m_lastCheckpointTime); // 默认为false,进行一次跟踪点统计后置为true m_hasChecked = true; m_lastCheckpointId = id; } #endif // !defined(ELPP_DISABLE_PERFORMANCE_TRACKING) && ELPP_LOGGING_ENABLED ELPP_UNUSED(id); ELPP_UNUSED(file); ELPP_UNUSED(line); ELPP_UNUSED(func); }
getFormattedTimeTaken 接口
getFormattedTimeTaken
接口用于获取经过调整后的时间戳的字符串形式。const base::type::string_t PerformanceTracker::getFormattedTimeTaken(struct timeval startTime) const { // 保留时间格式,不将其转换为秒、小时等(仅限性能跟踪) if (ELPP->hasFlag(LoggingFlag::FixedTimeFormat)) { base::type::stringstream_t ss; // 求timeval结构体之间的时间差(以毫秒或者微秒为单位),以m_timestampUnit为统计单位,默认性能跟踪单位为毫秒 ss << base::utils::DateTime::getTimeDifference(m_endTime, startTime, m_timestampUnit) << " " << base::consts::kTimeFormats[static_cast<base::type::EnumType>(m_timestampUnit)].unit; return ss.str(); } // 将指定的时间戳转化为指定时间单位的字符串形式,以m_timestampUnit为统计单位 return base::utils::DateTime::formatTime(base::utils::DateTime::getTimeDifference(m_endTime, startTime, m_timestampUnit), m_timestampUnit); }
相关类介绍
PerformanceTrackingData 类
PerformanceTrackingData
类主要作为性能跟踪回调的参数,传递性能跟踪统计需要的一些信息。class PerformanceTrackingData { public: enum class DataType : base::type::EnumType { Checkpoint = 1, //性能跟踪点的统计 Complete = 2 //整个代码块的性能跟踪统计 }; // Do not use constructor, will run into multiple definition error, use init(PerformanceTracker*) explicit PerformanceTrackingData(DataType dataType) : m_performanceTracker(nullptr), m_dataType(dataType), m_firstCheckpoint(false), m_file(""), m_line(0), m_func("") { } inline const std::string *blockName(void) const; inline const struct timeval *startTime(void) const; inline const struct timeval *endTime(void) const; inline const struct timeval *lastCheckpointTime(void) const; inline const base::PerformanceTracker *performanceTracker(void) const { return m_performanceTracker; } inline PerformanceTrackingData::DataType dataType(void) const { return m_dataType; } inline bool firstCheckpoint(void) const { return m_firstCheckpoint; } inline std::string checkpointId(void) const { return m_checkpointId; } inline const char *file(void) const { return m_file; } inline base::type::LineNumber line(void) const { return m_line; } inline const char *func(void) const { return m_func; } inline const base::type::string_t *formattedTimeTaken() const { return &m_formattedTimeTaken; } inline const std::string &loggerId(void) const; private: base::PerformanceTracker *m_performanceTracker; // 性能跟踪统计类 base::type::string_t m_formattedTimeTaken; // 经过调整后的时间戳的字符串形式。 PerformanceTrackingData::DataType m_dataType; // 性能跟踪统计的类型 bool m_firstCheckpoint; // 暂时未用上 std::string m_checkpointId; // 当前进行的性能跟踪点的ID const char *m_file; // 进行性能跟踪的源文件 base::type::LineNumber m_line; // 进行性能跟踪的行号 const char *m_func; // 进行性能跟踪的函数 inline void init(base::PerformanceTracker *performanceTracker, bool firstCheckpoint = false) { m_performanceTracker = performanceTracker; m_firstCheckpoint = firstCheckpoint; } friend class el::base::PerformanceTracker; };
DefaultPerformanceTrackingCallback 类
DefaultPerformanceTrackingCallback
类是默认性能跟踪回调类,其主要职责就是执行 easylogging++默认的性能跟踪统计。其实现如下:class DefaultPerformanceTrackingCallback : public PerformanceTrackingCallback { protected: void handle(const PerformanceTrackingData *data) { m_data = data; base::type::stringstream_t ss; // 代码块性能跟踪结束 if (m_data->dataType() == PerformanceTrackingData::DataType::Complete) { ss << ELPP_LITERAL("Executed [") << m_data->blockName()->c_str() << ELPP_LITERAL("] in [") << *m_data->formattedTimeTaken() << ELPP_LITERAL("]"); } else { // 性能跟踪点 ss << ELPP_LITERAL("Performance checkpoint"); if (!m_data->checkpointId().empty()) { ss << ELPP_LITERAL(" [") << m_data->checkpointId().c_str() << ELPP_LITERAL("]"); } ss << ELPP_LITERAL(" for block [") << m_data->blockName()->c_str() << ELPP_LITERAL("] : [") << *m_data->performanceTracker(); // 未禁用性能跟踪点的对比统计并且已经进行过跟踪点统计 if (!ELPP->hasFlag(LoggingFlag::DisablePerformanceTrackingCheckpointComparison) && m_data->performanceTracker()->m_hasChecked) { // 输出上一次跟踪点统计结束的时间 ss << ELPP_LITERAL(" ([") << *m_data->formattedTimeTaken() << ELPP_LITERAL("] from "); if (m_data->performanceTracker()->m_lastCheckpointId.empty()) { ss << ELPP_LITERAL("last checkpoint"); } else { ss << ELPP_LITERAL("checkpoint '") << m_data->performanceTracker()->m_lastCheckpointId.c_str() << ELPP_LITERAL("'"); } ss << ELPP_LITERAL(")]"); } else { ss << ELPP_LITERAL("]"); } } // 要输出的性能跟踪信息汇总后,使用el::base::Writer最终进行日志输出。 el::base::Writer(m_data->performanceTracker()->level(), m_data->file(), m_data->line(), m_data->func()).construct(1, m_data->loggerId().c_str()) << ss.str(); } private: const PerformanceTrackingData *m_data; };
el::base::Writer
类我们在CLOG
宏 Writer 对象的创建以及初始化、日志输出、日志信息保存 已经仔细介绍过了,这里就不多说了。
至此,性能跟踪的实现就介绍完了,下一篇我们开始分析崩溃处理的实现。
本文来自博客园,作者:节奏自由,转载请注明原文链接:https://www.cnblogs.com/DesignLife/p/16955360.html