日志模塊

Previews

日志系統(tǒng)是一個(gè)系統(tǒng)的核心組成部分玻粪,是展示系統(tǒng)運(yùn)行狀態(tài)峡竣、錯(cuò)誤追溯的最好方式租谈,搞明白日志的相關(guān)代碼有利于我們調(diào)試ceph
代碼中的各種鎖就不解釋了哈

總體設(shè)計(jì)思路

  1. 日志記錄采用異步模式
  2. 盡量使用宏定義來提高程序運(yùn)行速度
  3. 使用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)

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末靴姿,一起剝皮案震驚了整個(gè)濱河市沃但,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌佛吓,老刑警劉巖宵晚,帶你破解...
    沈念sama閱讀 219,270評論 6 508
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場離奇詭異维雇,居然都是意外死亡淤刃,警方通過查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,489評論 3 395
  • 文/潘曉璐 我一進(jìn)店門吱型,熙熙樓的掌柜王于貴愁眉苦臉地迎上來逸贾,“玉大人,你說我怎么就攤上這事唁影「荩” “怎么了?”我有些...
    開封第一講書人閱讀 165,630評論 0 356
  • 文/不壞的土叔 我叫張陵据沈,是天一觀的道長哟沫。 經(jīng)常有香客問我,道長锌介,這世上最難降的妖魔是什么嗜诀? 我笑而不...
    開封第一講書人閱讀 58,906評論 1 295
  • 正文 為了忘掉前任猾警,我火速辦了婚禮,結(jié)果婚禮上隆敢,老公的妹妹穿的比我還像新娘发皿。我一直安慰自己,他們只是感情好拂蝎,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,928評論 6 392
  • 文/花漫 我一把揭開白布穴墅。 她就那樣靜靜地躺著,像睡著了一般温自。 火紅的嫁衣襯著肌膚如雪玄货。 梳的紋絲不亂的頭發(fā)上,一...
    開封第一講書人閱讀 51,718評論 1 305
  • 那天悼泌,我揣著相機(jī)與錄音松捉,去河邊找鬼。 笑死馆里,一個(gè)胖子當(dāng)著我的面吹牛隘世,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播鸠踪,決...
    沈念sama閱讀 40,442評論 3 420
  • 文/蒼蘭香墨 我猛地睜開眼丙者,長吁一口氣:“原來是場噩夢啊……” “哼!你這毒婦竟也來了营密?” 一聲冷哼從身側(cè)響起蔓钟,我...
    開封第一講書人閱讀 39,345評論 0 276
  • 序言:老撾萬榮一對情侶失蹤,失蹤者是張志新(化名)和其女友劉穎卵贱,沒想到半個(gè)月后,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體侣集,經(jīng)...
    沈念sama閱讀 45,802評論 1 317
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡键俱,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,984評論 3 337
  • 正文 我和宋清朗相戀三年,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了世分。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片编振。...
    茶點(diǎn)故事閱讀 40,117評論 1 351
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡,死狀恐怖臭埋,靈堂內(nèi)的尸體忽然破棺而出踪央,到底是詐尸還是另有隱情,我是刑警寧澤瓢阴,帶...
    沈念sama閱讀 35,810評論 5 346
  • 正文 年R本政府宣布畅蹂,位于F島的核電站,受9級特大地震影響荣恐,放射性物質(zhì)發(fā)生泄漏液斜。R本人自食惡果不足惜累贤,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,462評論 3 331
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望少漆。 院中可真熱鬧臼膏,春花似錦、人聲如沸示损。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,011評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽检访。三九已至始鱼,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間烛谊,已是汗流浹背风响。 一陣腳步聲響...
    開封第一講書人閱讀 33,139評論 1 272
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留丹禀,地道東北人状勤。 一個(gè)月前我還...
    沈念sama閱讀 48,377評論 3 373
  • 正文 我出身青樓,卻偏偏與公主長得像双泪,于是被迫代替她去往敵國和親持搜。 傳聞我的和親對象是個(gè)殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,060評論 2 355

推薦閱讀更多精彩內(nèi)容