生產上報來了內核bug：mysql在作reset master時內核整個panic了。mysql

DBA同窗很是熱心的幫忙找到了從新步驟：就是一個地雷同樣的文件，只要open它，再fdatasync，kernel就panic。
從panic的代碼位置看，就是 jbd2_journal_commit_transaction() 裏的
J_ASSERT(journal->j_running_transaction != NULL);
判斷失敗觸發panicgit

可是，爲何jbd2在沒有running_transaction的時候也會提交事務？那就只能把全部喚醒kjournald2內核線程（裏面調用了jbd2_journal_commit_transaction）的地方——即wake_up(&journal->j_wait_commit)處都加上trace，因爲重現步驟是現成的，很快就定位到了緣由：open一個文件再直接fdatasync的時候，會調用ext4_sync_file ，裏面調用jbd2_log_start_commit開始提交jbd2的日誌，jbd2_log_start_commit裏會加鎖而後調用__jbd2_log_start_commit，代碼以下:sql

int __jbd2_log_start_commit(journal_t *journal, tid_t target)                      
{       
        /* 
         * Are we already doing a recent enough commit?                            
         */
        if (!tid_geq(journal->j_commit_request, target)) {
                /*
                 * We want a new commit: OK, mark the request and wakup the        
                 * commit thread.  We do _not_ do the commit ourselves.            
                 */
                journal->j_commit_request = target;
                jbd_debug(1, "JBD: requesting commit %d/%d\n",                     
                          journal->j_commit_request,
                          journal->j_commit_sequence);
                wake_up(&journal->j_wait_commit);
                return 1;
        }       
        return 0;
}

從trace的結果看，journal->j_commit_request的值爲2177452108，而target的值爲0,看上去j_commit_request顯然比target小，應該不會走到if判斷裏面去，可是其實是走了的，由於tid_geq的實現是：app

static inline int tid_geq(tid_t x, tid_t y)
{
        int difference = (x - y);
        return (difference >= 0);
}

unsigned int型2177452108減去0而後轉爲int型，猜猜結果是多少？等於 -2117515188 ！看上去好像tid_geq的實現又羅嗦又奇怪，因而翻了一下注釋，才發現，jbd2給每一個transaction一個tid，這個tid是不斷增加的，而它又是個unsigned int型，因此容易溢出，因而弄出來這麼一個tid_geq，把0當作是比2177452108更「晚」的tid，當commit_request爲2177452108而target爲0時，意思是：編號2177452108的tid已經提交了，0比2177452108更「晚」，因此有必要把0號transaction給commit一下，因而喚醒kjournald2（那句wake_up）。而這一喚醒，就發現沒有running_transaction，因而悲劇了。
從trace看，大部分傳入__jbd2_log_start_commit的target值都不是0，看來這個0來得蹊蹺，翻了一下upstream的代碼，找到了Ted在去年3月份提的一個patch：async

commit 688f869ce3bdc892daa993534dc6df18c95df931
Author: Theodore Ts'o 
  
  
  
  
   
   
   
   
Date:   Wed Mar 16 17:16:31 2011 -0400
    ext4: Initialize fsync transaction ids in ext4_new_inode()
    When allocating a new inode, we need to make sure i_sync_tid and
    i_datasync_tid are initialized.  Otherwise, one or both of these two
    values could be left initialized to zero, which could potentially
    result in BUG_ON in jbd2_journal_commit_transaction.
    (This could happen by having journal->commit_request getting set to
    zero, which could wake up the kjournald process even though there is
    no running transaction, which then causes a BUG_ON via the
    J_ASSERT(j_ruinning_transaction != NULL) statement.
    Signed-off-by: "Theodore Ts'o" 
   
   
   
   
     diff --git a/fs/ext4/ialloc.c b/fs/ext4/ialloc.c index 2fd3b0e..a679a48 100644 --- a/fs/ext4/ialloc.c +++ b/fs/ext4/ialloc.c @@ -1054,6 +1054,11 @@ got: } } + if (ext4_handle_valid(handle)) { + ei->i_sync_tid = handle->h_transaction->t_tid; + ei->i_datasync_tid = handle->h_transaction->t_tid; + } + err = ext4_mark_inode_dirty(handle, inode); if (err) { ext4_std_error(sb, err);

啊哈，就是它了，因爲i_sync_tid和i_datasync_tid都沒有正確賦值，因此帶上了默認的0值，一路傳給ext4_sync_file，然後面的__jbd2_log_start_commit又誤認爲0是一個要提交的新事務（其實此時尚未把當前事務掛到running_transaction上去),因此錯誤了。打上這個patch，再走重現步驟kernel也不panic了。post

既然這麼容易重現爲何其它機器上沒有遇到？緣由就是這個commit_request必須是一個很大的值，大到轉爲int型時會變爲負數。我試了一下在ext4上不停的建立空文件並fdatasync之，10分鐘左右commit_request才變爲一百萬，若是要讓它到二十億，至少還須要十四天，而線上的io壓力畢竟沒有人工壓力測試那麼大，因此幾個月後commit_request纔到二十億，才觸發了這個bug。
redhat最新的2.6.32-220內核是有這個問題的，你們多當心。測試

感謝@元雲和@希羽兩位同窗幫忙提供了重現步驟，內核修bug，最難的就是重現，兩位卻直接把步驟提供出來了，真是太體貼太客氣了！ui

======spa

原本想用ksplice來不重啓升級內核，這樣DBA就能夠不重啓機器修復這個bug，可是研究了一下ksplice，發現它要求加gcc參數 -ffunction-sections -fdata-sections 來編譯內核，而這兩個參數又和 -pg 參數衝突，而咱們的kernel trace須要用到 -pg ，因此....目前無解，尚未辦法用ksplice來幫助咱們在線升級內核。