Previews
日志系統(tǒng)是一個(gè)系統(tǒng)的核心組成部分玻粪,是展示系統(tǒng)運(yùn)行狀態(tài)峡竣、錯(cuò)誤追溯的最好方式租谈,搞明白日志的相關(guān)代碼有利于我們調(diào)試ceph
代碼中的各種鎖就不解釋了哈
總體設(shè)計(jì)思路
- 日志記錄采用異步模式
- 盡量使用宏定義來提高程序運(yùn)行速度
- 使用thread_local緩存一些東西
源碼解析
啟動
關(guān)鍵類
還是需要看代碼偷厦,大概知道里面的數(shù)據(jù)結(jié)構(gòu)
CephContext // ceph的全局上下文由捎,保存一些全局的東西
SubsystemMap // 這個(gè)是用來表示不同子系統(tǒng)的map兔综,比如mds osd等
ConfigValues // 這個(gè)就是存放配置文件的參數(shù),這個(gè)里面有SubsystemMap類型的成員變量
Log // 日志類狞玛,繼承Thread類
在程序啟動時(shí)會解析參數(shù)列表软驰,將參數(shù)的key-value存放在ConfigValues的實(shí)例對象的map中,同時(shí)初始化SubsystemMap(調(diào)用的是ConfigValues::set_logging函數(shù))
void ConfigValues::set_logging(int which, const char* val)
{
// 至少你應(yīng)該直到ceph是怎樣設(shè)置日志等級的哈心肪,不然你看不懂
int log, gather;
int r = sscanf(val, "%d/%d", &log, &gather);
if (r >= 1) {
// 如果只傳了1而不是1/5這種锭亏,那么gather等于log
if (r < 2) {
gather = log;
}
// 設(shè)置日志等級,就是我們設(shè)置的哪個(gè)1/2這個(gè)硬鞍,前面的1就是log的值慧瘤,2就是gather的值
subsys.set_log_level(which, log);
subsys.set_gather_level(which, gather);
}
}
然后調(diào)用全局初始化函數(shù)global_init,這個(gè)函數(shù)里面會初始化ceph的上下文類CephContext膳凝,這個(gè)類的構(gòu)造函數(shù)里面會去實(shí)例化Log類碑隆,日志類里面也有SubsystemMap類型的成員變量,用來標(biāo)識
當(dāng)前模塊和當(dāng)前日志等級
CephContext::CephContext()
{
...
// 將上面實(shí)例化的ConfigValues對象中的SubsystemMap類型變量傳個(gè)Log
_log = new ceph::logging::Log(&_conf->subsys);
...
}
然后會common_init_finish函數(shù)中調(diào)用Log::start()函數(shù)蹬音,去啟動日志線程上煤,如何啟動的參考之前的信號處理的分析文章(都是繼承的Thread類)
日志線程
下面有必要簡單介紹下Log類中的成員的作用
class Log : private Thread
{
using EntryRing = boost::circular_buffer<ConcreteEntry>;
using EntryVector = std::vector<ConcreteEntry>;
static const std::size_t DEFAULT_MAX_NEW = 100;
static const std::size_t DEFAULT_MAX_RECENT = 10000;
Log **m_indirect_this;
// 用來標(biāo)識子系統(tǒng)類型,和日志等級
const SubsystemMap *m_subs;
// 日志類進(jìn)出隊(duì)列的鎖
std::mutex m_queue_mutex;
// 日志文件flush到磁盤的鎖
std::mutex m_flush_mutex;
// 條件變量著淆,當(dāng)m_new的容量不足時(shí)需要等待m_new中的日志拷貝到m_flush中
std::condition_variable m_cond_loggers;
// 條件變量劫狠,當(dāng)新的日志進(jìn)入m_new中時(shí),需要通知日志線程進(jìn)行flush操作
std::condition_variable m_cond_flusher;
// 這兩個(gè)其實(shí)就是用來判斷程序是否處于加鎖狀態(tài)的
pthread_t m_queue_mutex_holder;
pthread_t m_flush_mutex_holder;
// 保存新來的日志,還未進(jìn)入flush階段
EntryVector m_new; ///< new entries
// 保存flush階段的日志
EntryVector m_flush; ///< entries to be flushed (here to optimize heap allocations)
// 用一個(gè)環(huán)形緩沖區(qū)來保存變量永部,當(dāng)緩沖區(qū)滿了独泞,新的數(shù)據(jù)會覆蓋舊的,正好實(shí)現(xiàn)了保存最近數(shù)據(jù)的功能
EntryRing m_recent; ///< recent (less new) entries we've already written at low detail
// 日志文件的路徑
std::string m_log_file;
// 日志文件的文件描述符
int m_fd = -1;
// user id 和group id
uid_t m_uid = 0;
gid_t m_gid = 0;
int m_fd_last_error = 0; ///< last error we say writing to fd (if any)
int m_syslog_log = -2, m_syslog_crash = -2;
int m_stderr_log = -1, m_stderr_crash = -1;
int m_graylog_log = -3, m_graylog_crash = -3;
std::string m_log_stderr_prefix;
std::shared_ptr<Graylog> m_graylog;
// 在flush階段用來保存日志內(nèi)容
std::vector<char> m_log_buf;
// 用來標(biāo)志日志線程是否需要停止苔埋,線程會一直去檢測這個(gè)變量懦砂,一旦為true就停止線程
bool m_stop = false;
// 容器size
std::size_t m_max_new = DEFAULT_MAX_NEW;
std::size_t m_max_recent = DEFAULT_MAX_RECENT;
bool m_inject_segv = false;
調(diào)用了start函數(shù)后就啟動了一個(gè)日志線程,該線程運(yùn)行的是Log::entry()這個(gè)函數(shù),下面看看這個(gè)函數(shù)
Log::entry()
void *Log::entry()
{
// 打開日志文件荞膘,獲得日志文件的文件描述符(多說一句其實(shí)文件描述符就是內(nèi)核中記錄已打開文件數(shù)組的索引)
reopen_log_file();
{
std::unique_lock lock(m_queue_mutex);
m_queue_mutex_holder = pthread_self();
// 只有m_stop不為真罚随,就一直循環(huán),(Log::stop函數(shù)才能置m_stop為真)
while (!m_stop) {
//
if (!m_new.empty()) {
m_queue_mutex_holder = 0;
lock.unlock();
// 進(jìn)入flush階段羽资,將日志內(nèi)容輸出到指定地方(日志文件淘菩、控制臺、系統(tǒng)日志等)
flush();
lock.lock();
m_queue_mutex_holder = pthread_self();
// 這里continue是為了防止在執(zhí)行flush函數(shù)時(shí)又有日志進(jìn)入屠升,在這continue就不用在下面wait了潮改,就可以實(shí)時(shí)打印日志
continue;
}
// 等待主程序調(diào)用submit_entry,將新的日志加入m_new中
m_cond_flusher.wait(lock);
}
m_queue_mutex_holder = 0;
}
flush();
return NULL;
}
flush函數(shù)
void Log::flush()
{
std::scoped_lock lock1(m_flush_mutex);
m_flush_mutex_holder = pthread_self();
{
std::scoped_lock lock2(m_queue_mutex);
m_queue_mutex_holder = pthread_self();
assert(m_flush.empty());
// 將m_new中的日志轉(zhuǎn)移到m_flush中腹暖,日志進(jìn)入flush階段
m_flush.swap(m_new);
// 這個(gè)時(shí)候m_new空了汇在,通知submit_entry可以接收新的日志了
m_cond_loggers.notify_all();
m_queue_mutex_holder = 0;
}
_flush(m_flush, false);
m_flush_mutex_holder = 0;
}
_flush函數(shù)(日志輸出的核心函數(shù))
void Log::_flush(EntryVector& t, bool crash)
{
long len = 0;
if (t.empty()) {
assert(m_log_buf.empty());
return;
}
if (crash) {
len = t.size();
}
for (auto& e : t) {
auto prio = e.m_prio; // 打印日志時(shí)傳進(jìn)來的
auto stamp = e.m_stamp; // 時(shí)間戳
auto sub = e.m_subsys; // 用來標(biāo)識不同子系統(tǒng)的, 比如osd, mds
auto thread = e.m_thread; // 這個(gè)是指向要打印日志的那個(gè)線程
auto str = e.strv(); // 日志的內(nèi)容
// 判斷是否需要打印脏答,比如你設(shè)置的日志等級為3趾疚,本日志為1(dout(1)),那么就為真
bool should_log = crash || m_subs->get_log_level(sub) >= prio;
bool do_fd = m_fd >= 0 && should_log;
// 系統(tǒng)日志,和上面同理
bool do_syslog = m_syslog_crash >= prio && should_log;
bool do_stderr = m_stderr_crash >= prio && should_log;
bool do_graylog2 = m_graylog_crash >= prio && should_log;
if (do_fd || do_syslog || do_stderr) {
const std::size_t cur = m_log_buf.size();
std::size_t used = 0;
const std::size_t allocated = e.size() + 80;
m_log_buf.resize(cur + allocated);
// 獲取m_log_buf的頭指針
char* const start = m_log_buf.data();
// 將指針移動到第一個(gè)為空的位置
char* pos = start + cur;
if (crash) {
used += (std::size_t)snprintf(pos + used, allocated - used, "%6ld> ", -(--len));
}
// 加上時(shí)間戳
used += (std::size_t)append_time(stamp, pos + used, allocated - used);
// 加上是哪個(gè)線程打印的日志以蕴,不是指本日志線程哈
used += (std::size_t)snprintf(pos + used, allocated - used, " %lx %2d ", (unsigned long)thread, prio);
// 加上日志數(shù)據(jù)
memcpy(pos + used, str.data(), str.size());
used += str.size();
pos[used] = '\0';
ceph_assert((used + 1 /* '\n' */) < allocated);
// 輸出到系統(tǒng)日志里
if (do_syslog) {
syslog(LOG_USER|LOG_INFO, "%s", pos);
}
// 輸出到標(biāo)準(zhǔn)輸出
if (do_stderr) {
std::cerr << m_log_stderr_prefix << std::string_view(pos, used) << std::endl;
}
/* now add newline */
pos[used++] = '\n';
if (do_fd) {
m_log_buf.resize(cur + used);
} else {
m_log_buf.resize(0);
}
// 你懂得吧,每次寫文件都是一個(gè)耗時(shí)的操作辛孵,這里的處理是將所有日志累計(jì)到一個(gè)量再一起寫入
if (m_log_buf.size() > MAX_LOG_BUF) {
_flush_logbuf();
}
}
if (do_graylog2 && m_graylog) {
m_graylog->log_entry(e);
}
// 記錄最近的日志
m_recent.push_back(std::move(e));
}
t.clear();
_flush_logbuf();
}
寫日志
ceph提供了很多中寫日志的宏丛肮,我這只分析dout
應(yīng)用舉例
dout(1) << "asok_command: " << command << " " << cmdmap
<< " (starting...)" << dendl;
定義, 簡單的宏定義,應(yīng)該很好看懂
#define dout(v) ldout((dout_context), (v))
#define dout_prefix *_dout
#if defined(WITH_SEASTAR) && !defined(WITH_ALIEN)
....
#elif defined(WITH_SEASTAR) && defined(WITH_ALIEN)
...
#define dout_impl(cct, sub, v) \
do { \
// 匿名函數(shù)魄缚,判斷這個(gè)日志要不要打印
const bool should_gather = [&](const auto cctX) { \
if constexpr (ceph::dout::is_dynamic<decltype(sub)>::value || \
ceph::dout::is_dynamic<decltype(v)>::value) { \
return cctX->_conf->subsys.should_gather(sub, v); \
} else { \
/* The parentheses are **essential** because commas in angle \
* brackets are NOT ignored on macro expansion! A language's \
* limitation, sorry. */ \
return (cctX->_conf->subsys.template should_gather<sub, v>()); \
} \
}(cct); \
\
if (should_gather) { \
ceph::logging::MutableEntry _dout_e(v, sub); \
static_assert(std::is_convertible<decltype(&*cct), \
CephContext* >::value, \
"provided cct must be compatible with CephContext*"); \
auto _dout_cct = cct; \
std::ostream* _dout = &_dout_e.get_ostream();
#define dendl_impl std::flush; \
_dout_cct->_log->submit_entry(std::move(_dout_e)); \
} \
} while (0)
#endif // WITH_SEASTAR
#define ldout(cct, v) dout_impl(cct, dout_subsys, v) dout_prefix
注意這個(gè)dout_prefix宝与,在編譯時(shí)會替換成*_dout,調(diào)用dout時(shí)變成一個(gè)std::ostream類型的指針,所以可以用<< 操作
上面這個(gè)宏在最后會調(diào)用Log::submit_entry函數(shù)冶匹,將這個(gè)日志實(shí)例對象加入到m_new中习劫,
submit_entry函數(shù)
void Log::submit_entry(Entry&& e)
{
...
if (unlikely(m_inject_segv))
*(volatile int *)(0) = 0xdead;
// wait for flush to catch up
// 這里是如果m_new超過了最大容量,需要等待m_new中的數(shù)據(jù)被挪到m_flush中
while (is_started() &&
m_new.size() > m_max_new) {
if (m_stop) break; // force addition
m_cond_loggers.wait(lock);
}
// 將日志對象放到m_new中
m_new.emplace_back(std::move(e));
// 通知日志線程處理這些日志
m_cond_flusher.notify_all();
...
}
一些小細(xì)節(jié)
都知道ceph是超級大佬寫的嚼隘,那肯定是有很多細(xì)節(jié)可以學(xué)習(xí)的
最近日志記錄的實(shí)現(xiàn)
ceph會記錄最近的日志打印诽里,使用了boost::circular_buffer<ConcreteEntry>,這個(gè)數(shù)據(jù)結(jié)構(gòu)飞蛹,這個(gè)數(shù)據(jù)結(jié)構(gòu)的特點(diǎn)就是它是一個(gè)大小固定的環(huán)形結(jié)構(gòu)谤狡,
新的數(shù)據(jù)一直向里面寫,寫滿之后會直接覆蓋老的數(shù)據(jù)卧檐,這樣就實(shí)現(xiàn)了記錄最近日志的功能
日志分級
我們在開發(fā)功能的時(shí)候墓懂,為了調(diào)試會加很多日志打印,但是上線的時(shí)候就把這些日志打印給干掉了霉囚,這其實(shí)不是很好捕仔,不能每次調(diào)試就又去加上吧,分級這個(gè)理念很不錯(cuò)
線程級緩存
我們知道ceph的日志是包裝成了一個(gè)Entry類的,但是每次實(shí)例化都會花費(fèi)很多性能榜跌,所以ceph做了一個(gè)線程級緩存
代碼在./src/common/StackStringStream.h中闪唆,有興趣可以看看,總的來說它搞了個(gè)inline static thread_local修飾的結(jié)構(gòu)體斜做,這個(gè)結(jié)構(gòu)體只要實(shí)例化一次苞氮,
只有在線程被銷毀時(shí)才會被銷毀,這就避免了每次打印日志都要實(shí)例化
記錄兩個(gè)知識點(diǎn)
c++中父類引用可以去指向子類實(shí)例對象瓤逼,但是不能通過這個(gè)父類引用對象直接訪問子類對象的特有成員和函數(shù)笼吟,如果這個(gè)子類繼承并實(shí)現(xiàn)了父類的方法,那么調(diào)用這個(gè)父類引用的這個(gè)方法霸旗,
其實(shí)是在調(diào)子類贷帮,通過這個(gè)特性可以訪問到子類特有的一些數(shù)據(jù),比如父類有方法:virtual int test(){} 诱告,子類繼承實(shí)現(xiàn)了這個(gè)方法:int test(){return a;} int a;撵枢,那么
父類就可以訪問到這個(gè)子類的a的值了, 具體可以看./src/log/Entry.h中的實(shí)現(xiàn)精居,
父類沒法直接隱式轉(zhuǎn)化成子類對象锄禽,但是子類要是實(shí)現(xiàn)了對應(yīng)的類型轉(zhuǎn)化函數(shù)就可以了,例子可以查看./src/log/Entry.h中的ConcreteEntry::ConcreteEntry& operator=(const Entry& e)