C++程序的调试一般有调试器、printf、日志文件三种。Linux下的调试器为gdb,关于gdb的使用甚至可以单独用一本书来说明,但是本章并不会过度讨论gdb,读者可以寻找相关的资料阅读。Gdb是C++程序调试中非常重要的调试手段,其有如下特点:
Gdb绝对是调试期的利器,另外一个调试期使用的既简单又实用的方法是printf,就是使用c库的函数printf输出变量到控制台。其优点是直观,可以完整的、清晰的观察程序的运行过程,而不需像gdb一样暂停程序。另外printf也只能用于开发调试环境,上线时服务器程序都是在后台运行的,printf将会失去作用。更重要的是因为gdb和printf都不会将数据存储,历史数据或历史操作都会在重启程序后消失。日志文件可以弥补gdb和printf的不足,我们需要一个具有如下功能的日志组件:
下面来探讨一下日志 的实现。
定义log_t类来封装对于日志配置、格式化、输出的操作。log_t主要的功能有:
class log_t
{
public:
log_t(int level_, const string& all_class_, const string& path_, const string& file_,
bool print_file_, bool print_screen_);
virtual ~log_t();
void mod_level(int level_, bool flag_);
void mod_class(const string& class_, bool flag_);
void mod_print_file(bool flag_);
void mod_print_screen(bool flag_);
bool is_level_enabled(int level_);
const char* find_class_name(const char* class_);
void log_content(int level_, const char* str_class_, const string& content_);
};
接口log_content 负责格式化和输出日志内容,其主要实现代码如下:
void log_t::log_content(int level_, const char* str_class_, const string& content_)
{
struct timeval curtm;
gettimeofday(&curtm, NULL);
struct tm tm_val = *localtime(&(curtm.tv_sec));
char log_buff[512];
::snprintf(log_buff, sizeof(log_buff), "%02d:%02d:%02d.%03ld %s [%ld] [%s] ",
tm_val.tm_hour, tm_val.tm_min, tm_val.tm_sec, curtm.tv_usec/1000,
g_log_level_desp[level_], gettid(), str_class_);
if (m_enable_file && check_and_create_dir(&tm_val))
{
m_file << log_buff << content_ << endl;
m_file.flush();
}
if (m_enable_screen)
{
printf("%s%s%s%s\n", g_log_color_head[level_], log_buff, content_.c_str(), g_log_color_tail[level_]);
}
}
其执行的主要过程如下:
为了保证日志接口尽可能的快,日志接口都是异步完成的其。时序图如下:
对于用户层而言,调用日志组件接口的开销为日志内容格式化和拷贝字符串到队列,而相对开销较大的写文件、输出屏幕操作则有日志线程完成,这样可以最大程度的保证用户层的高效运行。
我们定义log_service_t封装异步操作,对于格式化和输出,log_service_t仍然通过log_t实现,log_service_t的职责有四:
关键代码如下:
class log_service_t
{
public:
log_service_t();
~log_service_t();
int start(const string& opt_);
int stop();
LOG_IMPL_MACRO(async_logdebug, LOG_DEBUG);
LOG_IMPL_MACRO(async_logtrace, LOG_TRACE);
LOG_IMPL_MACRO(async_loginfo, LOG_INFO);
LOG_IMPL_MACRO(async_logwarn, LOG_WARN);
LOG_IMPL_MACRO(async_logerror, LOG_ERROR);
LOG_IMPL_MACRO(async_logfatal, LOG_FATAL);
};
由于各个日志级别的接口代码都是相似的,使用了LOG_IMPL_MACRO简化代码,LOG_IMPL_MACRO定义为:
#define LOG_IMPL_NONE_ARG(func, LOG_LEVEL) \
inline void func(const char* class_, const char* fmt_) \
{ \
if (m_log->is_level_enabled(LOG_LEVEL)) \
{ \
const char* class_name_str = m_log->find_class_name(class_); \
if (class_name_str) \
{ \
m_task_queue.produce(task_binder_t::gen(&log_t::log_content, m_log, LOG_LEVEL, \
class_name_str, string(fmt_))); \
} \
} \
}
#define LOG_IMPL_ARG1(func, LOG_LEVEL) \
template <typename ARG1> \
inline void func(const char* class_, const char* fmt_, const ARG1& arg1_) \
{ \
if (m_log->is_level_enabled(LOG_LEVEL)) \
{ \
const char* class_name_str = m_log->find_class_name(class_); \
if (class_name_str) \
{ \
str_format_t dest(fmt_); \
dest.append(arg1_); \
m_task_queue.produce(task_binder_t::gen(&log_t::log_content, m_log, LOG_LEVEL, \
class_name_str, dest.gen_result())); \
} \
} \
}
#define LOG_IMPL_MACRO(async_logdebug, LOG_DEBUG) \
LOG_IMPL_NONE_ARG(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG1(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG2(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG3(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG4(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG5(async_logdebug, LOG_DEBUG) \
LOG_IMPL_ARG6(async_logdebug, LOG_DEBUG)
受篇幅所限,没有附上所有宏展开的代码,log_service_t初始化的代码如下:
int log_service_t::start(const string& opt_)
{
if (m_log) return 0;
int level = 2;
string path = "./log";
string filename = "log";
bool print_file = true;
bool print_screen = false;
arg_helper_t arg(opt_);
if (!arg.get_option_value("-log_level").empty()) level = ::atoi(arg.get_option_value("-log_level").c_str());
if (!arg.get_option_value("-log_path").empty()) path = arg.get_option_value("-log_level");
if (!arg.get_option_value("-log_filename").empty()) path = arg.get_option_value("-log_filename");
if (arg.get_option_value("-log_print_file") == "false" || arg.get_option_value("-log_print_file") == "0")
{
print_file = false;
}
if (arg.get_option_value("-log_print_screen") == "true" || arg.get_option_value("-log_print_screen") == "1")
{
print_screen = true;
}
m_log = new log_t(level, arg.get_option_value("-log_class"), path, filename, print_file, print_screen);
m_thread.create_thread(task_binder_t::gen(&task_queue_t::run, &m_task_queue), 1);
return 0;
}
代码很简单,也很直观,需要对读者解释的是,初始化接口start的参数为字符串,这样做的好处是可以从配置文件中读入日志配置参数后直接传给log_service_t的start接口,而用户层完全不需要关心日志配置语法的细节。Start函数创建log_t实例后,创建单独线程执行任务队列,而任务队列中的所有任务就是写日志内容或输出日志内容。
关于格式化输出,使用使用了模板函数和多态机制保证了绝对的类型安全,这也是相对于sprintf的巨大优越点。class str_format_t 是用来格式化字符串的工具类,它使用sprintf的格式化语法,但是额外提供了排错和纠错功能:
关于基本类型的格式化模板函数:
template<typename T>
void append(T content_)
{
if (move_to_next_wildcard())
{
if (m_fmt_type.type == 'x')
{
char buff[64];
snprintf(buff, sizeof(buff), "0x%x", (unsigned int)content_);
m_num_buff = buff;
}
else
{
m_strstream << content_;
m_strstream >> m_num_buff;
}
int width = m_fmt_type.min_len > m_num_buff.length()? m_fmt_type.min_len - m_num_buff.length(): 0;
for (; width > 0; -- width)
{
m_result += m_fmt_type.fill_char;
}
}
else
{
m_strstream << content_;
m_strstream >> m_num_buff;
}
m_result += m_num_buff;
m_strstream.clear();//! clear error bit,not content
m_num_buff.clear();
}
关于字符串的特化函数:
void str_format_t::append(const string& str_)
{
if (move_to_next_wildcard())
{
int width = m_fmt_type.min_len > str_.length()? m_fmt_type.min_len -str_.length(): 0;
for (; width > 0; -- width)
{
m_result += m_fmt_type.fill_char;
}
}
m_result += str_;
}
move_to_next_wildcard 每次尝试移动到下一个%所在的位置,然后用值参数替换%的格式化。move_to_next_wildcard的整个开销是遍历字符串的开销:
bool str_format_t::move_to_next_wildcard()
{
m_fmt_type.clear();
char tmp = '\0';
for (; cur_format_index < m_fmt_len; ++ cur_format_index)
{
tmp = m_fmt[cur_format_index];
if (tmp != '%')
{
m_result += tmp;
continue;
}
char next = m_fmt[cur_format_index + 1];
if (next == '%')
{
cur_format_index += 1;
m_result += next;
continue;
}
//! 支持多种格式化 %c %s, %d, %ld, %u, %lu, %x, %X, 找到格式化的类型
//for (++cur_format_index; cur_format_index < m_fmt_len; ++ cur_format_index)
for (unsigned int i = 1 ; i <= 5; ++i)
{
char cur = m_fmt[cur_format_index + i];
if (cur == '\0' || cur == '%')
{
break;
}
else if (cur == 'c' || cur == 'd' || cur == 'u' || cur == 'x' ||
cur == 'f' || cur == 's')
{
m_fmt_type.type = cur;
m_fmt_type.min_len = ::atoi(m_fmt + cur_format_index + 1);
cur_format_index = cur_format_index + i + 1;
if (next == '0')
{
m_fmt_type.fill_char = next;
}
return true;
}
else if (cur == 'l')
{
char c_num = m_fmt[cur_format_index + i + 1];
if ('d' == c_num || 'u' == c_num)
{
m_fmt_type.type = c_num;
m_fmt_type.min_len = ::atoi(m_fmt + cur_format_index + 1);
cur_format_index = cur_format_index + i + 2;
if (next == '0')
{
m_fmt_type.fill_char = next;
}
return true;
}
}
}
m_result += tmp;
}
return false;
}
最基本的log_service_t的start接口提供了初始化日志组件时的配置,配置参数:
enum log_level_e
{
LOG_FATAL = 0,
LOG_ERROR,
LOG_WARN,
LOG_INFO,
LOG_TRACE,
LOG_DEBUG,
LOG_LEVEL_NUM
};
这其中除了log_path和log_filename不需要运行期配置外,其他的配置都有运行期修改的需求,比如运行期某个类别的日志被关闭了,但是为了跟踪某问题必须开启,如果不能动态修改日志配置往往会是开发人员面对问题时束手无策。对于-log_print_file 和-log_print_screen 都是用bool记录的,-log_level 是整型记录的,都是直接支持运行期修改的。有的读者可能指出日志不是有单独线程吗,而且使用线程组件的用户层也可能是多线程的,不就设计到了多线程竞争了吗?在明白此答案之前,先让我们缕一缕log中的结构:
对于-log_print_file 、-log_print_screen 和-log_level 都是多线程读取访问,某一时刻一个线程修改,并且三者都是基本类型的,不存在内存地址变化的问题,这样日志线程修改后会立即生效。但是对于-log_class,被开启的日志类别都被保存到set<string> 的结构中,多线程对其执行find操作是安全的,这个stl的多线程特性是明确支持的。但是若对set<string> 在运行期执行insert或erase后会使set<string>中的迭代器失效,被坏的情况是会引起读操作的线程崩溃,所以在运行期绝对不能对老的日志类别容器进行修改。难道日志类别就没办法运行期修改了吗?脑筋急转弯一下,既然不能修改老的,为什么不创建一个新的,然后用新的替换老的?为了使用这个方法,需要一些小技巧:
l 使用一个指针引用当前日志级别的容器,度线程总是获取该指针,然后执行find操作find_class_name 根据类别字符串去容器中查找是否存在。这里使用了原子操作ATOMIC_FETCH,在gcc的环境下可以把它定义为:
#define ATOMIC_FETCH(src_ptr) __sync_add_and_fetch(src_ptr, 0)
typedef set<string> str_set_t;
typedef vector<str_set_t*> ptr_vt_t;
str_set_t* m_enable_class_set;
const char* log_t::find_class_name(const char* class_)
{
str_set_t* pset = ATOMIC_FETCH(&m_enable_class_set);
str_set_t::iterator it = pset->find(class_);
if (it != pset->end())
{
return (*it).c_str();
}
return NULL;
}
l find_class_name对于存储日志类别的容器指针使用了原子操作,所以要保证指针对应的数据永远不被修改,即使有新的配置产生时,老的配置仍然不会被销毁,利用数据冗余保证无锁操作的线程安全,最后将新配置容器的指针替换老配置的指针即可,同样使用原子操作完成
#define ATOMIC_SET(src_ptr, v) (void)__sync_bool_compare_and_swap(src_ptr, *(src_ptr), v)
void log_t::mod_class(const string& class_, bool flag_)
{
str_set_t* pset = new str_set_t(m_enable_class_set->begin(), m_enable_class_set->end());
if (flag_)
{
pset->insert(class_);
}
else
{
pset->erase(class_);
}
m_class_set_history.push_back(pset);
ATOMIC_SET(&m_enable_class_set, pset);
}
总结以上无锁编程的技巧有:
l 对于stl的对象的多线程读操作是安全的
l 对于指针可以使用原子操作进行读取、更新、比较等操作
l 老的容器被保存而不是销毁,从而保证了获取了老数据的线程仍然能够工作正常,日志的类别字符串只有十几顶多几十个,这里做数据冗余的内存开销是可以忽略的。
日志的异步接口是由log_service_t定义的,前边介绍log_service_t的时候也提到了log_service_t一般是被单件使用的,如果每次调用singleton_t<log_service_t>::instance().async_logdebug(“XX”, “OhNice”);代码太长了,使用宏封装单件的操作:
#define LOG singleton_t<log_service_t>::instance()
#define LOGDEBUG(content) singleton_t<log_service_t>::instance().async_logdebug content
#define LOGTRACE(content) singleton_t<log_service_t>::instance().async_logtrace content
#define LOGINFO(content) singleton_t<log_service_t>::instance().async_loginfo content
#define LOGWARN(content) singleton_t<log_service_t>::instance().async_logwarn content
#define LOGERROR(content) singleton_t<log_service_t>::instance().async_logerror content
#define LOGFATAL(content) singleton_t<log_service_t>::instance().async_logfatal content
使用宏的好处是,比如logtrace可能会被到处使用了,而有可能其只在调试器有用,那么在release版本时候可以把宏LOGTRACE定义成空操作,当然若日志级别不开启的情况下,调用LOGTRACE的开销是很小的,一般情况可以忽略其影响。
使用示例:
int main(int argc, char* argv[])
{
LOG.start("-log_path ./log -log_filename log -log_class FF,XX -log_print_screen true -log_print_file true -log_level 6");
LOGDEBUG(("XX", "FFFFF"));
LOGTRACE(("XX", "FFFFF"));
LOGINFO(("XX", "FFFFF"));
LOGWARN(("XX", "FFFFF"));
LOGERROR(("XX", "FFFFF"));
LOGFATAL(("XX", "FFFFF"));
LOG.mod_class("TT", true);
sleep(1);
LOGFATAL(("TT", "FFFFF"));
LOGFATAL(("FF", "DSDFFFFF%s", string("SFWEGGGGGGGGG")));
LOG.stop();
return 0;
}