ceph log源码分析
ceph中log的处理方法是,主线程生成并提交日志条目给log线程处理,典型用法如下:
ldout (cct, log_level)<< msg << dendl, 其中msg是要写入日志的内容.
以src/librbd/librbd.cc为例:
// 子系统名称,ceph的每个log模块是一个子系统
#define dout_subsys ceph_subsys_rbd
// 根据子系统重新定义dout_prefix,因为它最初定义在src/commom/dout.h中
#undef dout_prefix
#define dout_prefix *_dout << "librbd: "
// aio_read中log的用法, bl是读入数据的buffer
ldout(ictx->cct, 10) << "Image::aio_read() buf=" << (void *)bl.c_str() << "~"
<< (void *)(bl.c_str() + len - 1) << dendl;
宏ldout和dend定义在文件src/common/dout.h中,如下所示:
#define dout_prefix *_dout
// sub: 子系统名称, v: 日志级别
#define dout_impl(cct, sub, v) \
do { \
if (cct->_conf->subsys.should_gather(sub, v)) { \
if (0) { \
char __array[((v >= -1) && (v <= 200)) ? 0 : -1] __attribute__((unused)); \
} \
static size_t _log_exp_length=80; \
ceph::log::Entry *_dout_e = cct->_log->create_entry(v, sub, &_log_exp_length); \
ostream _dout_os(&_dout_e->m_streambuf); \
CephContext *_dout_cct = cct; \
std::ostream* _dout = &_dout_os;
#define ldout(cct, v) dout_impl(cct, dout_subsys, v) dout_prefix
#define dendl std::flush; \
_ASSERT_H->_log->submit_entry(_dout_e); \
} \
} while (0)
// 宏替换之前
ldout(ictx->cct, 10) << "Image::aio_read() buf=" << (void *)bl.c_str() << "~"
<< (void *)(bl.c_str() + len - 1) << dendl;
// 宏替换之后
do { \
if (cct->_conf->subsys.should_gather(ceph_subsys_rbd, v)) { \
if (0) { \
char __array[((v >= -1) && (v <= 200)) ? 0 : -1] __attribute__((unused)); \
} \
static size_t _log_exp_length=80; \
ceph::log::Entry *_dout_e = cct->_log->create_entry(v, ceph_subsys_rbd, &_log_exp_length); \
ostream _dout_os(&_dout_e->m_streambuf); \
CephContext *_dout_cct = cct; \
std::ostream* _dout = &_dout_os;
*_dout << "librbd: "<< "Image::aio_read() buf=" << (void *)bl.c_str() << "~"
<< (void *)(bl.c_str() + len - 1) << std::flush; \
_dout_cct->_log->submit_entry(_dout_e); \
} \
} while (0)
从以上代码可以看出,由宏ldout和dendl组成一条完整的do { … } while(0)代码块,并在do中进行日志的生成和提交.其中利用**create_entry(来生成一个日志条目,利用submit_entry()**来提交一个日志条目.这两个工作都是由主线程调用log线程进行的处理的.
日志定义
log子系统主要的实现在目录src/log中,里面有一个很重要的类Log,它继承自线程类,自带线程处理日志功能. 因为打印日志,会影响系统的性能,特别是c++的流,对性能影响更明显.ceph这里采取了一些优化：
- ceph 对每个子系统的日志都预先定义了日志级别,并且可动态修改.
- 每条log都带有日志级别,日志级别越低,优先级越高.低于预先定义的级别才会被打印.
- log 信息只需要提交到Log类的线程即可,由log线程接管后台打印日志的任务.对提交log的线程影响较小
Log类的实现比较简单,维护两个队列,m_new用于提交新日志,flush的时候获取m_new的entry用来刷新,m_recent用来存放最近的日志,比如用户通过admin socket发送dump log的命令时，就会将m_recent的日志dump到文件:
class Log : private Thread
{
Log **m_indirect_this;
SubsystemMap *m_subs; // 每个子系统的日志级别的map
pthread_mutex_t m_queue_mutex; // 这个锁专门用来提交日志
pthread_mutex_t m_flush_mutex; // 这个锁用来打印提交的日志
pthread_cond_t m_cond_loggers;
pthread_cond_t m_cond_flusher;
pthread_t m_queue_mutex_holder;
pthread_t m_flush_mutex_holder;
EntryQueue m_new; // 提交日志的队列, EntryQueue定义见下文
EntryQueue m_recent; // 存放最近的日志
string m_log_file; // 日志文件名
int m_fd; // 日志文件描述符
// ceph的日志可以写入不同的地方
int m_syslog_log, m_syslog_crash; // syslog: 系统标准日志
int m_stderr_log, m_stderr_crash; // stderr: 系统标准输出
int m_graylog_log, m_graylog_crash; // graylog日志管理系统
shared_ptr<Graylog> m_graylog;
bool m_stop; // 日志线程是否终止
int m_max_new, m_max_recent; // m_new, m_recent队列的最大长度
void *entry(); // 线程入口,继承Thread的类必须定义自己的entry函数
void _flush(EntryQueue *q, EntryQueue *requeue, bool crash); // 将队列中的日志刷新到日志文件中
void _log_message(const char *s, bool crash);
public:
Log(SubsystemMap *s);
virtual ~Log();
void set_flush_on_exit();
void set_max_new(int n);
void set_max_recent(int n);
void set_log_file(std::string fn);
void reopen_log_file();
void flush(); // 刷新
void dump_recent(); // 打印最近的日志，一般用来响应admin socket的请求
Entry *create_entry(int level, int subsys); // 创建日志
void submit_entry(Entry *e); // 提交日志, 日志实体Entry见下文
void start(); // 启动日志的线程
void stop(); // 终止日志线程
};
log日志实体
每一个日志条目除了包括最基本的日志内容外,还包括一系列的其它元数据,比如产生日志的时间和线程,日志的优先级等.ceph对日志条目进行了优化,假设每条日志的长度为80个字节,然后把日志保存在一个预先分配好的内存缓冲m_streambuf中,这样可以避免内存的分配所带来的性能损失.如果日志的长度大于内存缓冲的大小 ,那么日志内存直接使用string来保存,具体的可以参数**PrebufferedStreambuf **类.
struct Entry {
utime_t m_stamp; // 生成日志的时间
pthread_t m_thread; // 生成日志的线程
short m_prio, m_subsys; // 日志的优先级以及日志所属的子系统
Entry *m_next; // 在日志队列中指向下一条日志记录
PrebufferedStreambuf m_streambuf; // 日志缓冲区,用于保存日志的内容
size_t m_buf_len; // 日志缓冲区的长度
size_t* m_exp_len; // 期待的日志长度
char m_static_buf[1];
// 将日志内容s添加到缓冲区中
void set_str(const std::string &s) {
ostream os(&m_streambuf);
os << s;
}
// 从缓冲区返回日志内容
std::string get_str() const {
return m_streambuf.get_str();
}
// returns current size of content
size_t size() const {
return m_streambuf.size();
}
// 将日志缓冲的内容写到dst指定的buffer中
int snprintf(char* dst, size_t avail) const {
return m_streambuf.snprintf(dst, avail);
}
};
log日志实体队列
ceph的日志队列使用单链表来实现
struct EntryQueue {
int m_len; // 队列长度
struct Entry *m_head, *m_tail; // 队头指针, 队尾打针
bool empty() const {
return m_len == 0;
}
// swap主用于刷新日志队列时,将日志队列中的所有日志放到另一队列上,然后对另一队列进行处理,从而避免影响原队列
void swap(EntryQueue& other) {
int len = m_len;
struct Entry *h = m_head, *t = m_tail;
m_len = other.m_len;
m_head = other.m_head;
m_tail = other.m_tail;
other.m_len = len;
other.m_head = h;
other.m_tail = t;
}
void enqueue(Entry *e) {
if (m_tail) {
m_tail->m_next = e;
m_tail = e;
} else {
m_head = m_tail = e;
}
m_len++;
}
Entry *dequeue() {
if (!m_head)
return NULL;
Entry *e = m_head;
m_head = m_head->m_next;
if (!m_head)
m_tail = NULL;
m_len--;
e->m_next = NULL;
return e;
}
};
log Thread
下来我们来看下log线程的具体操作
// 线程入口函数,如果日志队列不为空,即有日志,那么log线程把相应的日志flush到日志文件中.
void *Log::entry()
{
pthread_mutex_lock(&m_queue_mutex);
m_queue_mutex_holder = pthread_self();
while (!m_stop) {
if (!m_new.empty()) { // 有新日志
m_queue_mutex_holder = 0;
pthread_mutex_unlock(&m_queue_mutex);
flush(); // 刷新日志
pthread_mutex_lock(&m_queue_mutex);
m_queue_mutex_holder = pthread_self();
continue;
}
pthread_cond_wait(&m_cond_flusher, &m_queue_mutex);
}
m_queue_mutex_holder = 0;
pthread_mutex_unlock(&m_queue_mutex);
flush();
return NULL;
}
void Log::flush()
{
pthread_mutex_lock(&m_flush_mutex);
m_flush_mutex_holder = pthread_self();
pthread_mutex_lock(&m_queue_mutex);
m_queue_mutex_holder = pthread_self();
EntryQueue t; // 临时队列
t.swap(m_new); // O(1)的交换，这样m_new又可以接收新日志的提交了
pthread_cond_broadcast(&m_cond_loggers);
m_queue_mutex_holder = 0;
pthread_mutex_unlock(&m_queue_mutex); // 提前释放锁，以便其他线程继续提交
_flush(&t, &m_recent, false); // 真正打印临时队列的信息, 并且会记录到m_recent
// trim
while (m_recent.m_len > m_max_recent) { // m_recent有大小限制，超出部分删除
delete m_recent.dequeue();
}
m_flush_mutex_holder = 0;
pthread_mutex_unlock(&m_flush_mutex);
}
// 将日志刷到到日志文件
void Log::_flush(EntryQueue *t, EntryQueue *requeue, bool crash)
{
Entry *e;
while ((e = t->dequeue()) != NULL) {
unsigned sub = e->m_subsys;
// 当crash为true或者日志的级别大于优先级时记录日志
bool should_log = crash || m_subs->get_log_level(sub) >= e->m_prio;
// 将日志写入哪里,日志文件还是syslog,stderr,还是graylog
bool do_fd = m_fd >= 0 && should_log;
bool do_syslog = m_syslog_crash >= e->m_prio && should_log;
bool do_stderr = m_stderr_crash >= e->m_prio && should_log;
bool do_graylog2 = m_graylog_crash >= e->m_prio && should_log;
e->hint_size();
if (do_fd || do_syslog || do_stderr) {
// 日志长度的处理
size_t buflen = 0;
char *buf;
size_t buf_size = 80 + e->size();
// 日志长度是否大于64K
bool need_dynamic = buf_size >= 0x10000; //avoids >64K buffers
//allocation at stack
char buf0[need_dynamic ? 1 : buf_size];
if (need_dynamic) {
buf = new char[buf_size];
} else {
buf = buf0;
}
// 如果日志长度大于64K, buf[1];
// 如果日志长度小于64K, buf[buf_size]
// 在日志中添加额外信息,包括时间,线程,优先级等
if (crash)
buflen += snprintf(buf, buf_size, "%6d> ", -t->m_len);
// 日志的前缀,记录日志发生的时间
buflen += e->m_stamp.sprintf(buf + buflen, buf_size-buflen);
// 日志的内容,包括线程ID,消息优先级
buflen += snprintf(buf + buflen, buf_size-buflen, " %lx %2d ",
(unsigned long)e->m_thread, e->m_prio);
// 将日志缓冲中的内容写入buf中
buflen += e->snprintf(buf + buflen, buf_size - buflen - 1);
// 将buf中的最后一字符置为'\0'
if (buflen > buf_size - 1) { //paranoid check, buf was declared
//to hold everything
buflen = buf_size - 1;
buf[buflen] = 0;
}
// 将日志写入系统标准日志上
if (do_syslog) {
syslog(LOG_USER|LOG_INFO, "%s", buf);
}
// 将日志写入系统标准错误上
if (do_stderr) {
cerr << buf << std::endl;
}
// 将日志写入日志文件中
if (do_fd) {
buf[buflen] = '\n';
int r = safe_write(m_fd, buf, buflen+1);
if (r != m_fd_last_error) {
if (r < 0)
cerr << "problem writing to " << m_log_file
<< ": " << cpp_strerror(r)
<< std::endl;
m_fd_last_error = r;
}
}
if (need_dynamic)
delete[] buf;
}
if (do_graylog2 && m_graylog) {
m_graylog->log_entry(e);
}
// 将日志加入requeuen队列
requeue->enqueue(e);
}
}
Entry *Log::create_entry(int level, int subsys)
{
if (true) {
return new Entry(ceph_clock_now(NULL), // new一个entry对象
pthread_self(),
level, subsys);
} else {
// kludge for perf testing
Entry *e = m_recent.dequeue();
e->m_stamp = ceph_clock_now(NULL);
e->m_thread = pthread_self();
e->m_prio = level;
e->m_subsys = subsys;
return e;
}
}
void Log::submit_entry(Entry *e)
{
pthread_mutex_lock(&m_queue_mutex); // 前面提到的这把锁是用来提交entry的
// wait for flush to catch up
while (m_new.m_len > m_max_new)
pthread_cond_wait(&m_cond_loggers, &m_queue_mutex);
m_new.enqueue(e); // 进队列
pthread_cond_signal(&m_cond_flusher);
pthread_mutex_unlock(&m_queue_mutex);
}
log日志级别
ceph对不同的模块定义了不同的日志级别,只有当日志的级别小于等于预定义的值时,ceph才会把日志写入日志文件中,那么log线程是怎么样知道预定的日志级别呢,答案是Log类中的SubsystemMap,它记录了ceph中所有的日志模块以及相就的日志级别.它的定义如下:
// Subsystem代表ceph中的不同log子系统
struct Subsystem {
int log_level, gather_level; // 子系统的日志级别,后者很少用
std::string name; // 子系统名
Subsystem() : log_level(0), gather_level(0) {}
};
// SubsystemMap: 子系统图,用于保存ceph中所有的子系统
class SubsystemMap {
std::vector<Subsystem> m_subsys;
unsigned m_max_name_len;
friend class Log;
public:
SubsystemMap() : m_max_name_len(0) {}
int get_num() const {
return m_subsys.size();
}
int get_max_subsys_len() const {
return m_max_name_len;
}
// 添加一个子系统信息
void add(unsigned subsys, std::string name, int log, int gather);
void set_log_level(unsigned subsys, int log);
int get_log_level(unsigned subsys) const {
if (subsys >= m_subsys.size())
subsys = 0;
return m_subsys[subsys].log_level;
}
// 是否需要打印日志
// 如果当前日志级别小于等于设置的日志级别,就打印日志,否则不打印日志
bool should_gather(unsigned sub, int level) {
assert(sub < m_subsys.size());
return level <= m_subsys[sub].gather_level ||
level <= m_subsys[sub].log_level;
}
};
日志级别的载入是ceph配置项中很小的一部分,下面简单介绍下ceph配置项的初始化过程以及别的相关的知识.
ceph_context
ceph_context是ceph中最基础的类,它完成一些基本工作:比如说启动一些公共线程log,admin_socket,perfcount等,它还会负责ceph集群的配置初始化过程,这是通过新建m_config_t对象来实现的,当然ceph_context中还有其它一些重要的内容,限于篇幅,这里只介绍log相关的.
CephContext::CephContext(uint32_t module_type_)
: nref(1),
_conf(new md_config_t()), // 初始化配置对象
_log(NULL),
_module_type(module_type_),
_crypto_inited(false),
_service_thread(NULL),
_log_obs(NULL),
_admin_socket(NULL),
_perf_counters_collection(NULL),
_perf_counters_conf_obs(NULL),
_heartbeat_map(NULL),
_crypto_none(NULL),
_crypto_aes(NULL),
_lockdep_obs(NULL)
{
......
_log = new ceph::log::Log(&_conf->subsys); // 创建日志管理类对象
_log->start(); // 启动线程
......
}
ceph日志级别的载入
那么ceph的预定义日志级别在哪里,答案是config_opts.h,实际上,该文件定义了ceph集群所需要的所有配置项,一共包括三部分内容: OPTION, DEFAULT_SUBSYS, SUBSYS, 其中SUBSYS就是日志模块和级别的定义.如下所示:
// src/common/config_opts.h
// 配置文件里，包含三个部分：OPTION, DEFAULT_SUBSYS, SUBSYS
// include的时候，会根据不同情况选择不同部分，未被选择的项就会为空
......
OPTION(xio_portal_threads, OPT_INT, 2) // (选项名称，选项类型，选项值）
DEFAULT_SUBSYS(0, 5)
SUBSYS(lockdep, 0, 1)
SUBSYS(context, 0, 1) // (子系统名称，log级别，gather级别)
......
以下ceph配置相关的类m_config_t:
struct md_config_t {
......
// 这里需要取得option的值，并定义常量
// 定义特殊类型的OPTION
#define OPTION_OPT_INT(name) const int name;
#define OPTION_OPT_LONGLONG(name) const long long name;
#define OPTION_OPT_STR(name) const std::string name;
#define OPTION_OPT_DOUBLE(name) const double name;
#define OPTION_OPT_FLOAT(name) const float name;
#define OPTION_OPT_BOOL(name) const bool name;
#define OPTION_OPT_ADDR(name) const entity_addr_t name;
#define OPTION_OPT_U32(name) const uint32_t name;
#define OPTION_OPT_U64(name) const uint64_t name;
#define OPTION_OPT_UUID(name) const uuid_d name;
// 定义OPTION
#define OPTION(name, ty, init) OPTION_##ty(name)
// 定义其他不需要的两项 SUBSYS/DEFAULT_SUBSYS 为空
#define SUBSYS(name, log, gather)
#define DEFAULT_SUBSYS(log, gather)
// 把config_opts.h文件include进来, 实际上获取了所有的OPTION
#include "common/config_opts.h"
// 取消以前所有的宏定义
#undef OPTION_OPT_INT
#undef OPTION_OPT_LONGLONG
#undef OPTION_OPT_STR
#undef OPTION_OPT_DOUBLE
#undef OPTION_OPT_FLOAT
#undef OPTION_OPT_BOOL
#undef OPTION_OPT_ADDR
#undef OPTION_OPT_U32
#undef OPTION_OPT_U64
#undef OPTION_OPT_UUID
#undef OPTION
#undef SUBSYS
#undef DEFAULT_SUBSYS
......
};
// 定义一个枚举，实际上就是生成了每个子系统的下标，这里借助了枚举类型的自增
// 所以在文件中的位置决定了子系统在vector中的下标
enum config_subsys_id {
ceph_subsys_, // default
// 因为这里不需要OPTION字段，先定义为空
#define OPTION(a,b,c)
// 生成枚举item的宏
#define SUBSYS(name, log, gather) \
ceph_subsys_##name,
// DEFAULT_SUBSYS这里也不需要，定义为空
#define DEFAULT_SUBSYS(log, gather)
// 把config_iopts.h文件include进来, 实际上获取了所有的SUBSYS
#include "common/config_opts.h"
// 取消以前所有的宏定义
#undef SUBSYS
#undef OPTION
#undef DEFAULT_SUBSYS
ceph_subsys_max
};
以下是ceph配置类m_config_t的实现文件
md_config_t::md_config_t()
: cluster("ceph"),
// 头文件定义了name 常量，这里对常量进行初始化
#define OPTION_OPT_INT(name, def_val) name(def_val),
#define OPTION_OPT_LONGLONG(name, def_val) name((1LL) * def_val),
#define OPTION_OPT_STR(name, def_val) name(def_val),
#define OPTION_OPT_DOUBLE(name, def_val) name(def_val),
#define OPTION_OPT_FLOAT(name, def_val) name(def_val),
#define OPTION_OPT_BOOL(name, def_val) name(def_val),
#define OPTION_OPT_ADDR(name, def_val) name(def_val),
#define OPTION_OPT_U32(name, def_val) name(def_val),
#define OPTION_OPT_U64(name, def_val) name(((uint64_t)1) * def_val),
#define OPTION_OPT_UUID(name, def_val) name(def_val),
#define OPTION(name, type, def_val) OPTION_##type(name, def_val)
// 以下两项不需要
#define SUBSYS(name, log, gather)
#define DEFAULT_SUBSYS(log, gather)
// include文件进来
#include "common/config_opts.h"
// 取消所有的宏
#undef OPTION_OPT_INT
#undef OPTION_OPT_LONGLONG
#undef OPTION_OPT_STR
#undef OPTION_OPT_DOUBLE
#undef OPTION_OPT_FLOAT
#undef OPTION_OPT_BOOL
#undef OPTION_OPT_ADDR
#undef OPTION_OPT_U32
#undef OPTION_OPT_U64
#undef OPTION_OPT_UUID
#undef OPTION
#undef SUBSYS
#undef DEFAULT_SUBSYS
lock("md_config_t", true, false)
{
init_subsys();
}
void md_config_t::init_subsys()
{
// 将子系统加入vector，第一个参数就是头文件中定义的宏，就是下标
#define SUBSYS(name, log, gather) \
subsys.add(ceph_subsys_##name, STRINGIFY(name), log, gather);
#define DEFAULT_SUBSYS(log, gather) \
subsys.add(ceph_subsys_, "none", log, gather);
// 过滤选项
#define OPTION(a, b, c)
// include 文件
#include "common/config_opts.h"
// 取消所有的宏
#undef OPTION
#undef SUBSYS
#undef DEFAULT_SUBSYS
}
1043
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
