從虛擬化前端Bug學習分析Kernel Dump

前言

也許你們都知道,分析 Kernel Dump 有個經常使用的工具叫 Crash,在我剛開始學習分析 Kernel Dump 的時候,老是花大量的時間折騰這個工具的用法,卻老是記不住這個工具的功能。後來有一次在參加某次內部分享的時候,有位大佬說了一句話讓我印象很是深入:這些工具怎麼用的你們不用記,等到真正開始用的時候你就會猜到這個工具備什麼功能。
這篇文章我想經過分析一個實際的案例,儘可能把學習Kernel Dump須要用到的知識串起來,雖然某些知識也許只會在這個案例中用到,可是我相信所用到的方法是能夠應用到各個地方的。html

線上有一臺 VM 宕機了,恰好有抓到 dump,拿到一臺測試機上就能夠開始分析了。首先須要的是 kernel 版本對應的 symbol,若是事先不知道 kernel 的版本,能夠經過 `strings corefile | grep "Linux version"' 獲取到當前 corefile 的 kernel 版本,例如 3.10.0-862.14.4.el7.x86_64linux

在獲取到內核版本以後,根據相應的發行版以及系統架構到特定的 symbol 發佈頁面下載 symbol,這裏的發行版是 Centos,能夠到 http://debuginfo.centos.org/ 下載。若是是 Ubuntu 發行版,能夠到 http://ddebs.ubuntu.com/ 下載。要找到指定 kernel 版本的 symbol 很簡單,只須要拿着 kernel 版本 3.10.0-862.14.4.el7.x86_64 搜一下就能找到了,一般咱們須要的 symbol 的只有下面這三個中的兩個,可是我老是記不住是哪兩個,因此我會把三個都下載下來並安裝:kernel-debug-debuginfo-3.10.0-862.14.4.el7.x86_64.rpm、kernel-debuginfo-3.10.0-862.14.4.el7.x86_64.rpm、kernel-debuginfo-common-x86_64-3.10.0-862.14.4.el7.x86_64.rpm。在安裝的時候因爲依賴的關係須要先安裝 common 的 symbol 才能安裝其它 symbol,另外若是測試機上的 kernel 版本比 corefile 的版本新,須要加上 --force 選項才能安裝上。redis

在 symbol 安裝完以後,就能夠經過 crash 載入 corefile 和 symbol 了。ubuntu

[root@iZxxx1Z crash]# crash /lib/debug/lib/modules/3.10.0-862.14.4.el7.x86_64/vmlinux i-2xxxpe.236725344.208176-2019-02-27-22\:44\:20

crash 7.2.3-8.el7
Copyright (C) 2002-2017  Red Hat, Inc.
Copyright (C) 2004, 2005, 2006, 2010  IBM Corporation
Copyright (C) 1999-2006  Hewlett-Packard Co
Copyright (C) 2005, 2006, 2011, 2012  Fujitsu Limited
Copyright (C) 2006, 2007  VA Linux Systems Japan K.K.
Copyright (C) 2005, 2011  NEC Corporation
Copyright (C) 1999, 2002, 2007  Silicon Graphics, Inc.
Copyright (C) 1999, 2000, 2001, 2002  Mission Critical Linux, Inc.
This program is free software, covered by the GNU General Public License,
and you are welcome to change it and/or distribute copies of it under
certain conditions.  Enter "help copying" to see the conditions.
This program has absolutely no warranty.  Enter "help warranty" for details.

GNU gdb (GDB) 7.6
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-linux-gnu"...

WARNING: kernel relocated [168MB]: patching 82671 gdb minimal_symbol values

      KERNEL: /lib/debug/lib/modules/3.10.0-862.14.4.el7.x86_64/vmlinux
    DUMPFILE: i-2xxxpe.236725344.208176-2019-02-27-22:44:20
        CPUS: 4 [OFFLINE: 3]
        DATE: Wed Feb 27 22:44:18 2019
      UPTIME: 11:34:59
LOAD AVERAGE: 0.20, 0.07, 0.06
       TASKS: 436
    NODENAME: iZ2xxxpeZ
     RELEASE: 3.10.0-862.14.4.el7.x86_64
     VERSION: #1 SMP Wed Sep 26 15:12:11 UTC 2018
     MACHINE: x86_64  (2500 Mhz)
      MEMORY: 16 GB
       PANIC: "kernel BUG at drivers/virtio/virtio_ring.c:278!"
         PID: 278
     COMMAND: "kworker/2:1H"
        TASK: ffff917c6d3b3f40  [THREAD_INFO: ffff917c64798000]
         CPU: 2
       STATE: TASK_RUNNING (PANIC)

經過 crash 載入 corefile 的時候,crash 會自動輸出一段信息,這段信息包含了系統的一些基本信息,如 CPU、內存、架構等。若是後面分析的時候還想看這部分信息,能夠經過 sys 命令來查看。這裏咱們須要重點關注的信息是
PANIC: "kernel BUG at drivers/virtio/virtio_ring.c:278!"
這個信息告訴咱們,系統觸發了位於 drivers/virtio/virtio_ring.c 這個文件的第 278 行的 Bug,這裏系統之因此知道是 Bug,是由於編寫這段代碼的大佬在這裏埋了一個檢測的點,這個待會咱們會在源碼裏看到。
在看完上面的信息後,個人習慣是先看看當時系統在作什麼,經過 bt 命令能夠看到當時的調用堆棧:後端

crash> bt
PID: 278    TASK: ffff917c6d3b3f40  CPU: 2   COMMAND: "kworker/2:1H"
 #0 [ffff917c6479b8a0] die at ffffffff8b82f96b
 #1 [ffff917c6479b8d0] do_trap at ffffffff8bf1cea0
 #2 [ffff917c6479b920] do_invalid_op at ffffffff8b82c284
 #3 [ffff917c6479b9d0] invalid_op at ffffffff8bf28aee
    [exception RIP: virtqueue_add+1186]
    RIP: ffffffffc023a382  RSP: ffff917c6479ba80  RFLAGS: 00010097
    RAX: 0000000000000081  RBX: ffff917c6c67d000  RCX: 0000000000000002
    RDX: 0000000000000081  RSI: ffff917c6479bc00  RDI: ffff917c6c67d000
    RBP: ffff917c6479bae8   R8: 0000000000000001   R9: ffff917c6b48a380
    R10: ffff917c6b410000  R11: 0000000000000002  R12: ffff917c6479bc18
    R13: ffff917c6479bc18  R14: ffff917c6479bc00  R15: 0000000000000001
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0018
 #4 [ffff917c6479ba80] __kmalloc at ffffffff8b9fbeb0
 #5 [ffff917c6479baf0] virtqueue_add_sgs at ffffffffc023a437 [virtio_ring]
 #6 [ffff917c6479bb48] __virtblk_add_req at ffffffffc03874b2 [virtio_blk]
 #7 [ffff917c6479bc68] virtio_queue_rq at ffffffffc03876f9 [virtio_blk]
 #8 [ffff917c6479bcb8] blk_mq_dispatch_rq_list at ffffffff8bb2a8b6
 #9 [ffff917c6479bd50] blk_mq_do_dispatch_sched at ffffffff8bb2f76e
#10 [ffff917c6479bd98] blk_mq_sched_dispatch_requests at ffffffff8bb3012e
#11 [ffff917c6479bde8] __blk_mq_run_hw_queue at ffffffff8bb29362
#12 [ffff917c6479be10] blk_mq_run_work_fn at ffffffff8bb295c5
#13 [ffff917c6479be20] process_one_work at ffffffff8b8b613f
#14 [ffff917c6479be68] worker_thread at ffffffff8b8b71d6
#15 [ffff917c6479bec8] kthread at ffffffff8b8bdf21

上圖打印的信息包含函數調用堆棧和各寄存器的值,這裏挑幾個比較重要的寄存器講一下。 RIP 指向正在執行的指令地址,在發生宕機以前,系統最後執行的函數是 virtqueue_add,致使宕機的語句位於 virtqueue_add+1186。根據 x86_64 Linux 系統的函數調用約定,RDI, RSI, RDX, RCX, R8, R9爲傳入函數的前六個參數,若是參數超過六個,第七個以上的參數將經過棧傳遞。注意在實際函數執行的過程當中,寄存器的值可能會改變。
如今來看看 ffffffffc023a382+1186 這行代碼究竟是什麼,經過 dis 命令能夠查看到對應的彙編。但當咱們執行dis virtqueue_add+1186的時候,發現報錯了,報錯的內容是 symbol 有重複。centos

crash> dis virtqueue_add+1186
dis: virtqueue_add+1186: duplicate text symbols found:
ffffffffc0239ee0 (t) virtqueue_add [virtio_ring]
ffffffffc023ab73 (t) virtqueue_add [virtio_ring]

咱們能夠經過 RIP 的值來計算出當前的 virtqueue_add 對應的是哪一個 symbol,計算方法很簡單,只要把 RIP 的值減去偏移量 1186 便可。數據結構

crash> p/x 0xffffffffc023a382-1186
$1 = 0xffffffffc0239ee0

經過 dis ffffffffc0239ee0 能夠打印出 virtqueue_add 的彙編,找到 virtqueue_add+1186架構

0xffffffffc023a378 <virtqueue_add+1176>:        mov    0x60(%rbx),%eax
0xffffffffc023a37b <virtqueue_add+1179>:        jmpq   0xffffffffc023a299 <virtqueue_add+953>
0xffffffffc023a380 <virtqueue_add+1184>:        ud2
0xffffffffc023a382 <virtqueue_add+1186>:        ud2

該行彙編其實是 ud2 ,這是一條 undefined 的語句,也正是由於這條語句讓系統宕機了。這個時候一般應該往上找,看看以前執行過的指令是什麼。這裏上一條指令是 jmpq ,這是無條件跳轉語句,跳轉到 virtqueue_add+953,也就是說 ud2 指令的上一條指令必定不是 jmpq 這條,能夠猜到應該是前面有某個跳轉直接跳到這裏來了,往上找找就能夠找到函數

0xffffffffc0239ef4 <virtqueue_add+20>:  mov    %rsi,-0x48(%rbp)
0xffffffffc0239ef8 <virtqueue_add+24>:  mov    %edx,-0x2c(%rbp)
0xffffffffc0239efb <virtqueue_add+27>:  mov    %ecx,-0x38(%rbp)
0xffffffffc0239efe <virtqueue_add+30>:  mov    %r8d,-0x58(%rbp)
0xffffffffc0239f02 <virtqueue_add+34>:  mov    %r9,-0x60(%rbp)
0xffffffffc0239f06 <virtqueue_add+38>:  je     0xffffffffc023a384 <virtqueue_add+1188>
0xffffffffc0239f0c <virtqueue_add+44>:  cmpb   $0x0,0x59(%rdi)
0xffffffffc0239f10 <virtqueue_add+48>:  mov    %rdi,%rbx
0xffffffffc0239f13 <virtqueue_add+51>:  jne    0xffffffffc023a05d <virtqueue_add+381>
0xffffffffc0239f19 <virtqueue_add+57>:  mov    -0x2c(%rbp),%eax
0xffffffffc0239f1c <virtqueue_add+60>:  cmp    %eax,0x38(%rdi)
0xffffffffc0239f1f <virtqueue_add+63>:  jb     0xffffffffc023a382 <virtqueue_add+1186>

能夠看到跳轉的語句是 jb 0xffffffffc023a382 <virtqueue_add+1186>,跳轉的條件是 %eax 小於 [%rdi + 0x38]。那 %eax 和 [%rdi + 0x38] 裏面存的值是什麼呢?這個時候就須要對照源碼來看了。經過 dis -l 能夠看到函數所在的源文件,可是直接執行 dis -l ffffffffc0239ee0 會發現沒有源文件的信息,這種狀況一般是對應的 debug 模塊沒有導進來。經過 mod 命令能夠看到當前的模塊,找到咱們須要的模塊,經過 mod -s 找到模塊對應的目錄,再經過相同的命令導入便可,如:工具

crash> mod -s virtio_ring
     MODULE       NAME                      SIZE  OBJECT FILE
ffffffffc023c0e0  virtio_ring              22746  /usr/lib/debug/usr/lib/modules/3.10.0-862.14.4.el7.x86_64/kernel/drivers/virtio/virtio_ring.ko.debug
crash> mod -s virtio_ring /usr/lib/debug/usr/lib/modules/3.10.0-862.14.4.el7.x86_64/kernel/drivers/virtio/virtio_ring.ko.debug
     MODULE       NAME                      SIZE  OBJECT FILE
ffffffffc023c0e0  virtio_ring              22746  /usr/lib/debug/usr/lib/modules/3.10.0-862.14.4.el7.x86_64/kernel/drivers/virtio/virtio_ring.ko.debug

把全部缺乏的模塊導入進來以後,再次執行dis -l ffffffffc0239ee0就能夠看到對應的源文件了。部分 virtqueue_add 源代碼以下:

241 static inline int virtqueue_add(struct virtqueue *_vq,
    242                                 struct scatterlist *sgs[],
    243                                 unsigned int total_sg,
    244                                 unsigned int out_sgs,
    245                                 unsigned int in_sgs,
    246                                 void *data,
    247                                 gfp_t gfp)
    248 {
    249         struct vring_virtqueue *vq = to_vvq(_vq);
    250         struct scatterlist *sg;
    251         struct vring_desc *desc;
    252         unsigned int i, n, avail, descs_used, uninitialized_var(prev), err_idx;
    253         int head;
    254         bool indirect;
    255
    256         START_USE(vq);
    257
    258         BUG_ON(data == NULL);
    259
    260         if (unlikely(vq->broken)) {
    261                 END_USE(vq);
    262                 return -EIO;
    263         }
    264
    265 #ifdef DEBUG
    266         {
    267                 ktime_t now = ktime_get();
    268
    269                 /* No kick or get, with .1 second between?  Warn. */
    270                 if (vq->last_add_time_valid)
    271                         WARN_ON(ktime_to_ms(ktime_sub(now, vq->last_add_time))
    272                                             > 100);
    273                 vq->last_add_time = now;
    274                 vq->last_add_time_valid = true;
    275         }
    276 #endif
    277
    278         BUG_ON(total_sg > vq->vring.num);
    279         BUG_ON(total_sg == 0);
    280
    281         head = vq->free_head;
    282
    283         /* If the host supports indirect descriptor tables, and we have multiple
    284          * buffers, then go indirect. FIXME: tune this threshold */
    285         if (vq->indirect && total_sg > 1 && vq->vq.num_free)
    286                 desc = alloc_indirect(_vq, total_sg, gfp);
    287         else
    288                 desc = NULL;
    289
    290         if (desc) {
    291                 /* Use a single buffer which doesn't continue */
    292                 indirect = true;
    293                 /* Set up rest to use this indirect table. */
    294                 i = 0;
    295                 descs_used = 1;
    296         } else {
    297                 indirect = false;
    298                 desc = vq->vring.desc;
    299                 i = head;
    300                 descs_used = total_sg;
    301         }

經過dis -l ffffffffc0239ee0打印出的信息並結合以前的分析,能夠知道:1. virtqueue_add 的前五個參數分別是 struct virtqueue、struct scatterlist、 unsigned int、 unsigned int、 unsigned int 類型的,對應的是 RDI, RSI, RDX, RCX, R8 這五個寄存器的值。2. 觸發 bug 的語句是第 278 行的  BUG_ON(total_sg > vq->vring.num);
經過 struct virtqueue ffff917c6c67d000 能夠解析出第一個參數的結構:

crash> struct virtqueue ffff917c6c67d000
struct virtqueue {
  list = {
    next = 0xffff917bbefa82c8,
    prev = 0xffff917bbefa82c8
  },
  callback = 0xffffffffc0387000,
  name = 0xffff917c6c7a1dcc "req.0",
  vdev = 0xffff917bbefa8000,
  index = 0,
  num_free = 1,
  priv = 0xffffadff81b5e010
}

回到剛剛咱們討論的 %eax 和 [%rdi + 0x38] ,[%rdi + 0x38] 實際上就是 virtqueue 中偏移量爲 0x38 的值,經過 struct -o virtqueue 能夠打印出 virtqueue 各成員的偏移:

crash> struct -o virtqueue
struct virtqueue {
   [0] struct list_head list;
  [16] void (*callback)(struct virtqueue *);
  [24] const char *name;
  [32] struct virtio_device *vdev;
  [40] unsigned int index;
  [44] unsigned int num_free;
  [48] void *priv;
}
SIZE: 56

這裏又出現了一個問題,0x38 是十進制的 56,而這個結構體的大小總共只有 56 個字節,難道是「溢出」了?仔細閱讀代碼後發現,代碼裏有一句 struct vring_virtqueue *vq = to_vvq(_vq);,to_vvq 是一個宏,定義以下 #define to_vvq(_vq) container_of(_vq, struct vring_virtqueue, vq),實際上這就是對 container_of 的一個封裝,container_of 的功能跟字面意思很接近,這裏 virtqueue 類型的 _vq 變量其實是 vring_virtqueue 類型的 vq 變量的一個成員變量,經過 container_of(_vq, struct vring_virtqueue, vq) 把 vq 計算出來。咱們經過struct -o vring_virtqueue來查看 vring_virtqueue 的結構:

crash> struct -o vring_virtqueue
struct vring_virtqueue {
    [0] struct virtqueue vq;
   [56] struct vring vring;
   [88] bool weak_barriers;
   [89] bool broken;
   [90] bool indirect;
   [91] bool event;
   [92] unsigned int free_head;
   [96] unsigned int num_added;
  [100] u16 last_used_idx;
  [104] bool (*notify)(struct virtqueue *);
  [112] bool we_own_ring;
  [120] size_t queue_size_in_bytes;
  [128] dma_addr_t queue_dma_addr;
  [136] struct vring_desc_state desc_state[];
}
SIZE: 136

能夠看到實際上 virtqueue 結構就在 vring_virtqueue 偏移爲 0 的地方,所以能夠直接經過 struct vring_virtqueue ffff917c6c67d000來解析
vring_virtqueue 結構:

crash> struct vring_virtqueue ffff917c6c67d000
struct vring_virtqueue {
  vq = {
    list = {
      next = 0xffff917bbefa82c8,
      prev = 0xffff917bbefa82c8
    },
    callback = 0xffffffffc0387000,
    name = 0xffff917c6c7a1dcc "req.0",
    vdev = 0xffff917bbefa8000,
    index = 0,
    num_free = 1,
    priv = 0xffffadff81b5e010
  },
  vring = {
    num = 128,
    desc = 0xffff917c6bf68000,
    avail = 0xffff917c6bf68800,
    used = 0xffff917c6bf69000
  },
  weak_barriers = true,
  broken = false,
  indirect = true,
  event = false,
  free_head = 94,
  num_added = 0,
  last_used_idx = 38531,
  notify = 0xffffffffc0249a50,
  we_own_ring = true,
  queue_size_in_bytes = 5126,
  queue_dma_addr = 17917444096,
  desc_state = 0xffff917c6c67d088
}

所以 [%rdi + 0x38] 實際上獲取的是 vring 結構裏偏移量爲 0 的即第一個成員的值,這裏獲取到的值就是 128。如今咱們已經經過這種方法獲取到觸發 bug 的語句中 BUG_ON(total_sg > vq->vring.num);的 vq->vring.num 值了,而 total_sg 其實是 virtqueue_add 的第三個參數,保存在 RDX 寄存器裏,是 0x81,即十進制的 129。

至此,我只是分析了這幾個數據結構中相關的變量內容,尚未解釋這些變量或者函數的含義,如今咱們已經驗證了觸發 BUG 的條件 total_sg > vq->vring.num,可是爲何會出現這種狀況呢?要分析這幾個變量的值須要回溯到調用這個函數的函數,最終可能須要一直回溯到發起 IO 請求的應用層程序,這顯然是一件很是麻煩的事情。換一個角度來想,total_sg 是 vm 須要的 scatterlist 的總數,scatterlist 是一個跟物理內存有關的結構,這裏能夠簡單理解爲 vm 所須要的物理內存,而 vring 是 virtio 先後端數據傳輸的載體,這裏能夠簡單理解先後端數據傳輸的能力。直觀的感受是 total_sg 確實不該該比 vring.num 大,但實際上 total_sg 只比 vring.num 大 1,並且這裏 total_sg 的值與我剛開始的想法不同,因爲 total_sg 是 unsigned int 類型的,而這裏的比較是 total_sg > vq->vring.num,所以我開始的想法是 total_sg 下溢出了。分析到這裏,我抱着試一試的態度把 BUG_ON(total_sg > vq->vring.num); 丟到 Google 上搜了一把,發現這行代碼已經在某個版本中 patch 掉了,最新的 kernel 裏把 BUG_ON 改爲了低一級的 WARN_ON_ONCE,同時把條件改爲了 total_sg > vq->vring.num && !vq->indirect。也就是說,在使用了 indirect descriptors 的狀況下,是容許 total_sg > vq->vring.num 這中狀況出現的,那如何驗證 vm 有沒有使用 indirect descriptors 呢?實際上在 vring_virtqueue 中的成員 indirect 標示了是否使用 indirect descriptors,在上面執行 struct vring_virtqueue ffff917c6c67d000 的時候已經把 indirect 的值打印出來了,vm 確實使用了 indirect descriptors,所以這個 bug 實際上觸發得並不合理,僅僅只判斷 total_sg > vq->vring.num 就觸發宕機的條件太過嚴格了。

總結

這個宕機問題到這裏就算分析完了,最後解決的方案是升級內核,考慮到目前 Centos 官方還未接受該 patch,須要手動編譯修復或經過第三方 repo 升級。實際上不少奇奇怪怪的問題均可以經過升級內核來解決,可是最新的內核一樣可能遇到奇奇怪怪的問題,誰知道下一個發現內核 bug 後寫了 patch 最後被社區接受的會不會是本身呢?但願你們經過這篇文章能有所收穫。文章寫得很差或不對的地方請各位大佬不吝賜教。



本文做者:半人前

閱讀原文

本文爲雲棲社區原創內容,未經容許不得轉載。

相關文章
相關標籤/搜索