1. 程式人生 > >幾個日誌輸出的解釋

幾個日誌輸出的解釋

我們通過原始碼,找到下面一段,該段實現了上述日誌的輸出。

  if ((my_now – rli->mts_last_online_stat)>=

           mts_online_stat_period)

        {

         sql_print_information(“Multi-threadedslave statistics%s: “

                                “seconds elapsed = %lu; “

                                “events assigned = %llu; “

                                “worker queues filled over overrun level = %lu;”

                                “waited due a Worker queue full = %lu; “

                                “waited due the total size = %lu; “

                                “waited at clock conflicts = %llu “

                               “waited(count) when Workers occupied = %lu “

                                “waited when Workers occupied = %llu”,

                                rli->get_for_channel_str(),

                                static_cast<unsignedlong>

                                (my_now – rli->mts_last_online_stat),

                                rli->mts_events_assigned,

                                rli->mts_wq_overrun_cnt,

                                rli->mts_wq_overfill_cnt,

                                rli->wq_size_waits_cnt,

                                rli->mts_total_wait_overlap,

                                rli->mts_wq_no_underrun_cnt,

                                rli->mts_total_wait_worker_avail);

          rli->mts_last_online_stat=my_now;   

 通過這一句(my_now – rli->mts_last_online_stat),  以及最後一句rli->mts_last_online_stat=my_now;   可以得知, seconds elapsed 就是上一次統計跟這一次統計的時間間隔。

而mts_online_stat_period =120秒,硬程式碼,因此就是幾乎每隔120秒,就有上述日誌的輸出。 通過進一步檢視原始碼,初步瞭解上述日誌資訊的含義,如下:

events assigned:總共有多少個event被分配執行,計的是總數

worker queues filled over overrun level:多執行緒同步中,worker 的私有佇列長度超長的次數,計的是總數。

waited due a Worker queue full :因為worker的佇列超長而產生等待的次數,計的是總數。

waited due the total size :超過最大size的次數,這個由引數slave_pending_jobs_size_max  指定。

waited at clock conflicts :因為邏輯時間產生衝突的等待時間,單位是納秒。

waited (count) when Workers occupied :因為workder被佔用而出現等待的次數。(總計值)。

waited when Workersoccupied :因為workder被佔用而出現等待的總時間,總計值,單位是納秒。

 

第三種:page_cleaner執行緒的輸出日誌

 

如圖,資訊如下:

 

2016-03-24T17:45:28.005117Z 0 [Note] InnoDB:page_cleaner: 1000ms intended loop took 4750ms.The settings might not beoptimal. (flushed=1519 and evicted=0, during the time.)

查詢原始碼,發現是上面的日誌由下面一段程式碼輸出:

        if (ret_sleep == OS_SYNC_TIME_EXCEEDED) {

            ulint   curr_time = ut_time_ms();

            if (curr_time >next_loop_time + 3000) {

                if (warn_count == 0) {

                    ib::info() << “page_cleaner: 1000ms”

                        ” intended loop took “

                        <<1000 + curr_time

                           – next_loop_time

                        <<“ms. The settings might not”

                        ” be optimal. (flushed=”

                        <<n_flushed_last

                        <<” and evicted=”

                        <<n_evicted

                        <<“, during the time.)”;

                    if (warn_interval >300) {

                        warn_interval= 600;

                    }else {

                        warn_interval*= 2;

                    }

                    warn_count= warn_interval;

                } else {

                    –warn_count;

                }

            } else {

                /* reset counter */

                warn_interval= 1;

                warn_count= 0;

            }

            next_loop_time= curr_time + 1000;

            n_flushed_last= n_evicted = 0;

        }

通過分析原始碼, 輸出上述日誌的條件是curr_time> next_loop_time + 3000 ,即比原定的迴圈時間next_loop_time多3000毫秒,而next_loop_time的標準時間是1000毫秒,即1秒鐘做一次重新整理頁的操作。

loop took 4750ms ,即是這次重新整理迴圈的實際經歷時間。

後面還有一個(flushed=1519 and evicted=0,during the time.)這樣的日誌,即對應n_flushed_last與n_evicted 變數,而這兩個變數又由n_flushed_list與n_flushed_lru賦值。

./storage/innobase/buf/:3322:                 n_flushed_last +=n_flushed_list;

./storage/innobase/buf/:3321:                 n_evicted += n_flushed_lru;

而n_flushed_list與n_flushed_lru賦值函式為pc_wait_finished,如下,我們來看看該函式的註釋。

pc_wait_finished(&n_flushed_lru,&n_flushed_list);

/**

Wait until all flush requests are finished.

@param n_flushed_lru    numberof pages flushed from the end of the LRU list.

@param n_flushed_list   numberof pages flushed from the end of the

            flush_list.

@return         trueif all flush_list flushing batch were success. */

static

bool

pc_wait_finished(

    ulint*  n_flushed_lru,

    ulint*  n_flushed_list)

{

。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。

}

通過原始碼的註釋,我們獲知如下資訊:

n_flushed_lru   number of pages flushed from the end of the LRU list.

n_flushed_lru  這個值表示從lru 列表尾部重新整理的頁數,也就是日誌中如evicted=0 指標的所表示的值,如果該值不為零,則存在innodb buffer不夠的嫌疑。

n_flushed_list  這個是從重新整理列表中重新整理的頁數,也就是髒頁數,也就是日誌中flushed=1519 的值。