微博某業務數據庫連續兩次 oom 問題分析

背景

微博某業務有若干機器在有突增訪問的時候，兩個從庫的連接數不均勻。實例數少的從庫與另一臺，連接數比例從日常的1:1變成2：1。并且反而連接數較少的從庫被OOM了。

環境

• 出現問題:

  時常有抓站等原因造成瞬間大量訪問，

• OS 版本:

  Centos 6.5

• kernel版本:

  2.6.32-431

• 服務器:

  CPU : Intel(R) Xeon(R) CPU E5-2407 v2 @ 2.40GHz

  2 * 4 core = 8 core

  物理內存 64GB

• MySQL版本:

  5.5.12

• MySQL部署情況:

• • 每個端口有兩個從庫

  • 每機器上1-2個MySQL實例,單實例buffer_pool_size設置為20G

  </li> </ul>

  • 分析前掌握的信息:

  • • 該業務有兩個從庫，簡稱A和B

    • 兩個從庫分別在兩臺不同的物理機上，A從庫所在機器部署了兩個實例，而B所在機器上部署該業務的一個實例。

    • B從庫所在機器的free內存要比A所在機器要富裕的多。

    • 平常A與B的連接數均為4K多，比例1：1左右

    </li> </ul>

    第一次OOM,內核compact

    【分析過程】

    先是收到B從庫的連接數報警，B從庫的連接數從日常的4K漲到10K+，而A從庫最低僅2K

    

    

    登錄A從庫機器，top看cpu消耗,發現sys比usr要高不少，這非常不正常

    

    再A從庫機器上利用perf看sys cpu消耗，也就是內核態cpu在做什么

    

    發現 compaction_alloc 這個內核函數竟然占據cpu周期近乎一半，我們看下源碼這個函數的定義:

    /*
    
    
     * This is a migrate-callback that "allocates" freepages by taking pages
     * from the isolated freelists in the block we are migrating to.
     */
        static struct page *compaction_alloc(struct page *migratepage,
                        unsigned long data,int **result)
        {        struct compact_control *cc = (struct compact_control *)data;          struct page *freepage;    
        /* Isolate free pages if necessary */
        if (list_empty(&cc->freepages)) {
            isolate_freepages(cc->zone, cc);            
    
        if (list_empty(&cc->freepages))                
            return NULL;
        }
    
        freepage = list_entry(cc->freepages.next, struct page, lru);
        list_del(&freepage->lru);
        cc->nr_freepages--;    
        return freepage;
        }</code></pre> 
    
    這個函數嘗試在整合內存碎片,將隔離出來的空閑頁從本zone內低地址移動到zone內末端。
     那究竟是什么原因觸發內核進行這個操作的呢？
     
      
    我們需要進一步研究內核 算法。簡單來說,可以理解為做的事情是重組內存中碎片，目的是整理出更大的物理上連續的區域。觸發的原因會有以下原因:
     
      
     
       
     
    /proc/sys/vm/compact_node 寫入一個node number，會導致在指定的numa node上發生compaction
     
     
       
     
    內核嘗試分配 high-order page 高階物理內存失敗，然后重組內存，將可移動的內存碎片整合在一起來獲取連續的內存
     
     
      
     
      
    (可移動的內存為用戶程序訪問的物理內存，對應不可移動的為內核在使用的物理內存.)
     
      
    原理如圖:
     
      
     
      
    了解了原理，我們再通過perf看下 compaction_alloc 函數的調用棧:
     
      
     
      
    此時A從庫的機器free看顯示為0，MySQL嘗試申請申請高階物理內存失敗，于是觸發內核通過移動 可移動內存 這種方式來整理碎片，以滿足MySQL內存需求，在之后的內存分配的分析中，我們也會看到這一步實際上已經進入了 內存慢速分配流程 。sys cpu花費大量的時間來進行碎片整理，MySQL被"拖"住了，threads running(不是thread connected)堆積的越來越多，qps也降低的很快，MySQL變得越來越無法響應請求。最后A從庫上的MySQL實例被OOM了。至于B的連接數比A要高很多，是因為正常的時候兩個從庫通過域名做的負載均衡。但是出現問題的時候，請求轉發到響應更快，free更充足的B上了。
     
      
    調整策略:
     
      
     
       
     
    禁用透明大頁
     
    echo "never" > /sys/kernel/mm/transparent_hugepage/enabled
     
     
      
     
      
    第二次OOM，內核reclaim
     
      
    【分析過程】
     上次關閉透明大頁之后，情況緩解了不少。有一段時間沒發生過oom的問題了。直到有一次業務被抓站，接口調用增加幾倍，并發連接數飆升，之上的問題再次發生，B比A連接數高了四倍，A從庫的響應時間間歇性的拉長。同時A從庫發現大量慢查。A從庫所在的機器的sys cpu同樣又飆高了。顯然A從庫所在服務器又“困”在了某個地方
     
      
    仍然先看sys cpu高的原因，內核在做什么:
     
      
     50.73%  [kernel]               [k] _spin_lock
      2.98%  libpthread-2.12.so      [.] pthread_mutex_lock
      2.90%  libpthread-2.12.so      [.] pthread_mutex_unlock
      1.94%  libpthread-2.12.so      [.] __lll_lock_wait
      1.59%  [kernel]                [k] futex_wake
      1.43%  [kernel]                [k] __audit_syscall_exit
      1.38%  [kernel]                [k] copy_user_generic_string
      1.35%  [kernel]                [k] system_call
      1.07%  [kernel]                [k] schedule
      0.99%  [kernel]                [k] hash_futex
     
      
    sys cpu看來大部分都消耗在 _spin_lock 上。但是內核在很多對資源的申請和釋放的時候都會通過spin lock對臨界資源進行保護。需要進一步分析 __spin_lock 的來源。
     
      
    繼續看pstack看 MySQL所有線程的調用棧:
     
      
     
      
    很多線程hang在了malloc()調用上,繼續看
     
      
    show engine innodb status 觀察MySQL線程爭用熱點
     
      
    localhost.(none)>show engine innodb status\G
    --Thread 140673550292736 has waited at buf0buf.c line 2766 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140674568324864 has waited at trx0trx.c line 1622 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140679185143552 has waited at buf0buf.c line 2766 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140672371988224 has waited at buf0buf.c line 2766 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140672599955200 has waited at buf0buf.c line 2766 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140673035118336 has waited at trx0trx.c line 1622 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140672392488704 has waited at trx0trx.c line 207 for 0.00 seconds the semaphore:
    waiters flag 1--Thread 140674877961984 has waited at trx0trx.c line 1622 for 0.00 seconds the semaphore:
    waiters flag 1略    
     
      
    找到對應的源碼，上面這些線程是在競爭 kernel_mutex ，并且 waiters flag 為1，說明這些線程都在等待持有 kernel_mutex 的線程釋放mutex，那MySQL的這個 kernel_mutex 跟我們perf看到os kernel的 __spin_lock 調用有什么關系呢？
     
      
    InnoDB線程同步機制
     
      
    我們知道linux線程同步有Mutex,spin lock,條件變量,rw lock等多種同步機制，InnoDB并沒有直接使用系統的同步機制，而是自己定義了互斥結構數據結構 kernel_mutex ,將系統的spin lock,mutex,和條件變量融合一起
     
      
     
     
      
    如圖, kernel_mutex mutex對象的中重要的結構成員為os_event和lock_word。
     
      
     
       
     
    kernel_mutex 主要涉及 mutex_create , mutex_enter , mutex_exit 函數，會分別使用glibc的malloc()和free()調用動態分配和釋放內存
     
     
       
     
    封裝mutex和條件變量，圖中綠色框區域
     
    MySQL線程之間發送異步信號來進行同步主要通過 os_event_struct 結構體中的 os_mutex (封裝os的 pthread_mutex_t )和 cond_var (封裝os的 pthread_cond_t )成員對象實現。當InnoDB在獲取鎖的時候，首先先努力自旋一段時間，如果超過 innodb_sync_spin_loops 的閾值，就會通過函數 os_event_wait_low() 在 os_event_struct->cond_var 上等待。如圖，當某個線程釋放了鎖的時候，通過 os_cond_broadcast 嘗試發送廣播喚醒所有等待 os_event_struct->cond_var 條件變量的線程.這些線程被喚醒后又繼續競爭爭搶 os_event_struct->os_mutex
     
     
       
     
    spin lock，圖中黃色框區域
     
    通過lock_word做spin wait。線程想要爭搶鎖的時候先判斷這個值，如果 lock_word 為1就繼續自旋等待。如果發現其他線程釋放了鎖該值變為0的時候，就通過 test_and_set 改為1，"告訴"其他線程這把鎖被持有了
     
     
      
     
      
    InnoDB這樣設計的目的都是延緩線程被掛起并進入os wait的速度，因為每一次進入os wait等待被喚醒或者喚醒都會進行一次上下文切換.但是也只能是延緩，并不能阻止，如果持續惡化得不到環境，最后仍然會進入os的等待隊列，將會產生大量的上下文切換。但是有兩個問題:
     
      
     
       
     
    kernel_mutex 是個全局鎖，保護事務，buffer pool,鎖，等InnoDB存儲引擎實現的大部分對象.當MySQL突然有大量訪問，并發一旦非常高的時候，mutex沖突非常劇烈，此時臨界區變得非常大，同時也會浪費cpu很多時間空轉。所以這也解釋了sys cpu大量消耗在自選空轉中
     
     
       
     
    并且并發高的時候會頻繁調用 malloc() 申請內存，而glibc本身的 malloc() 本書頻繁調用系統 mutex_lock() 和 unlock() ，在多線程高并發場景下并且資源不足的場景下，也會造成系統各種mutex競爭嚴重。大量線程被掛起等待os  pthread_cond_broadcast 廣播被喚醒，隨之而來的是大量的上下文切換
     
     
      
     
      
    通過dstat看到此時cpu每秒有近20W次的上下文切換，綜上所述，sys cpu負載高主要以下:
     
      
     
       
     
    (1)cpu內核態spin,大量線程cpu在內核態自旋等待
     
     
       
     
    (2)系統上下文切換,又分為:
     
     
      
     
      
     
       
     
        
     
         
     
    spin仍然失敗的，最終進入os wait，調用 pthread_cond_wait 等待條件滿足時被喚醒
     
     
         
     
    malloc()頻繁加減os mutex，且系統內存緊張
     
     
        
     
     
      
     
      
    numa機制內存分配策略對競爭的影響
     
      
    我們繼續觀察內存分配使用的情況.
     
      
    sar -B 看內存頁回收，其中 pgscank/s ，對應kswapd回收， pgscand/s 對應的MySQL線程直接回收
     
      
     
      
    pgscand/s 不為0，說明內存資源緊張,MySQL直接回收內存。
     
      
    可是free命令看內存free并沒有用光。經過一番調查發現是numa搞的鬼
     
      
    用 numactl --hardware 命令看:
     
      
    available: 2 nodes (0-1)
    node 0 cpus: 0 1 2 3node 0 size: 32733 MB
    node 0 free: 1900 MB
    node 1 cpus: 4 5 6 7node 1 size: 32768 MB
    node 1 free: 20 MB
    node distances:
    node   0   1 
      0:  10  20 
      1:  20  10
     
      
    雖然內存整體free沒有用光，但是在numa默認的內存分配機制下，內存使用嚴重不均,node0還十分充足，但是node1幾乎用光
     
      
    如果node1可用內存已經用光，之下來會發生什么？
     
      
    資源嚴重不足下內存的慢速回收流程
     
      
    先簡單說下內存的回收機制分為:
     
      
     
       
     
    內核態進程回收 (kswapd)
     
     
       
     
    用戶態的進程直接回收 (__alloc_pages_direct_reclaim)
     
     
      
     
      
    perf top 看此時cpu cycles:
     
      
    Samples: 657K of event 'cycles', Event count (approx.): 112241881, DSO: [kernel]
     63.70%  [k] alloc_pages_current            
     36.01%  [k] __alloc_pages_nodemask         
      0.25%  [k] alloc_pages_vma                
      0.04%  [k] __alloc_pages_direct_reclaim
     
      
    調用棧路徑如下:
     
      
    |          |--52.11%--  get_page_from_freelist
     
      
    |          |          __alloc_pages_direct_reclaim
     
      
    |          |          __alloc_pages_slowpath
     
      
    |          |          __alloc_pages_nodemask
     
      
    |          |          alloc_pages_current
     
      
    |          |          pte_alloc_one
     
      
    |          |          __pte_alloc
     
      
    .........略.....
     
      
    我們看下慢速分配直接回收內存路徑:
     
      
     
      
     
      
    我們看到大量的用戶態進程直接回收，已經到了圖中5的位置，此時分配內存已經相當困難，
     
      
    __alloc_pages_direct_reclaim
     
      
    函數主要調用try_to_free_pages回收一些最近很少用的page cache中的頁面。另外try_to_free_pages函數也會喚醒內核pdflush線程回寫磁盤，增加sys cpu load。
     
      
     
     
      
    之后還是再次努力的調用get_page_from_freelist嘗試分配,如果還是失敗,就到了最艱難的時刻:檢查
     
      
    oom_killer_disabled 參數設置，如果oom_killer并沒有禁用則進入 __alloc_pages_may_oom 流程.
     
      
    最終，A從庫上的實例掛掉了，我們在看message日志看到了OOM的信息
     
      
     
      
    至于kernel關于oom的流程及選擇策略之后也會寫一篇專門介紹，這里不再展開
     
      
    另外通過研究慢速流程發現:除了直接回收內存，也會通過 __alloc_pages_direct_compact 整合碎片以獲得更大的連續內存，也就是第一次OOM發生的直接原因。
     
      
    至此整個過程，我們總結sys高不是單一因素造成，是一系列因素相互作用導致。
     
      
    總體路徑如下:
     
      
    numa機制->部分node free不足-> 并發導致資源競爭—> 內存回收進入慢速回收->compact or reclaim ->oom 流程
     
      
    調整策略
     
      
     
       
     
    關于numa機制
     
     
      
     
      
     
       
     
        
     
         
     
    關閉numa特性 (BIOS中關閉或者os關閉)
     
     
         
     
    mysqld_safe文件中調整啟動參數,numa內存分配策略調整為interleave
     
     
        
     
     
      
     
      
     
       
     
    保證充足的free內存
     
    增大這以上內核參數的值,測試加起來2G夠用
     
     
      
     
      
     
       
     
        
     
         
     
    vm.min_free_bytes 系統留給kernel的內存，小于這個值發生直接回收
     
     
         
     
    vm.extra_free_bytes 系統留給應用的free內存，避免突發訪問kswapd回收不及時
     
     
        
     
     
      
     
      
     
       
     
    內存管理上
     
     
      
     
      
     
       
     
        
     
         
     
    glibc庫的malloc()在高并發多線程場景下頻繁分配和釋放內存，會造成頻繁加解鎖。是性能上的殺器。建議換成jemalloc()或者google的tcmalloc()
     
     
        
     
     
      
     
      
     
       
     
    MySQL 參數調整
     
     
      
     
      
     
       
     
        
     
         
     
    innodb_thread_concurrency = 32
     
    5.5默認值為0，不限制。但是目前上述DB并發較高，進入innodb層的事務線程過多，并發過大會惡化資源競爭，同時增加CPU SYS的消耗
     
     
         
     
    innodb_sync_spin_loops 微調
     
    默認值30，自旋鎖和上下文切換的平衡，也就是spin wait和os wait的平衡,增大此值會延緩進入os wait的時間，如果系統上下文切換已經 非常大了，可適當增大此值，讓線程在進入os wait之前再多spin一段時間
     
     
         
     
    innodb_spin_wait_delay = 12 微調
     
    默認值6，如果context switch非常高，可以增加此值，但不需要加的太多，因為我們的cpu比較挫（2個物理cpu,每個4核）
     
     
        
     
     
      
     
      
     
       
     
    降低MySQL被OOM_killer干掉的可能
     
     
      
     
      
     
       
     
        
     
         
     
    echo -15 > /proc/{pidof mysqld}/oom_adj
     
     
        
     
     
      
     
      
     
       
     
    升級MySQL版本
     
     
      
     
      
     
       
     
        
     
         
     
    kernel_mutex 是個全局mutex，5.5版本中， kernel_mutex 保護的資源過多，包括事務，鎖，日志，buffer pool等等都通過這個mutex保護，一旦并發訪問上來，性能會下降的非常厲害。在5.6中已對該mutex進行了拆分,提高了并發的性能
     
     
        
     
     
      
     
      
     
     
      
     
     
      
    來自：http://mp.weixin.qq.com/s/hXtCzSnlVfo9Cq92538ipw