SystemTapで真犯人を捕まえろ!Linuxトラブルシューティング探偵団 番外編(3)(3/4 ページ)

» 2009年03月25日 00時00分 公開
[高田哲生, 前野真輝NTT OSSセンタ]

その名はdma_alloc_coherent()

 SystemTapの結果を基に、われわれはひとまずccissのスタックトレースを解析してみました。そのスタックトレースは以下のようなものです。

_alloc_pages
           dma_alloc_pages
           dma_alloc_coherent
           cmd_alloc[cciss]
           cciss_ioctl[cciss]
           __d_lookup
           path_release
           __link_path_walk
           blkdev_ioctl
           link_path_walk
           cciss_ioctl32_passthru[cciss]
           find_extend_vma
           __up_read sys_ioctl

 __alloc_pagesがalloc_pages()の本体です。下の行に行くにつれて、この処理の呼び出し元へと戻っていきます。[]で囲まれているのは、その関数があるモジュール名です。これを順にさかのぼりつつ解析していって、ついに問題の個所を発見することに成功しました!

207 void *
208 dma_alloc_coherent(struct device *dev, size_t size, dma_addr_t *dma_handle,
209           unsigned gfp)
210 {

(中略)

225 again:
226      memory = dma_alloc_pages(dev, gfp, get_order(size)); //alloc_pagesによる物理メモリ確保
227      if (memory == NULL)
228           return NULL;
229
230      {
231           int high, mmu;
232           bus = virt_to_bus(memory);
233           high = (bus + size) >= dma_mask;
234           mmu = high;
235           if (force_iommu && !(gfp & GFP_DMA))
236                 mmu = 1;
237           if (no_iommu || dma_mask < 0xffffffffUL) {
238                 if (high) {
239                     if (!(gfp & GFP_DMA)) {
240                     gfp |= GFP_DMA;   // ←本来なら物理メモリを解放してから
241                     goto again;     // ←again(225行目)へジャンプすべき
242                 }
243                 goto free;
244           }
245           mmu = 0;
246       }

(中略)

263 free:
264       free_pages((unsigned long)memory, get_order(size));
265       /* XXX Could use the swiotlb pool here too */
266       return NULL;
267 }

 上記ソースコードは、RHEL 4 Update2のkernel-2.6.9-22.ELのarch/x86_64/kernel/pci-gart.cから抜粋したものです。

 226行目のdma_alloc_pages()が__alloc_pages()につながっており、実際に物理メモリを確保している処理です。ここで241行目に注目してください。とある条件を満たすと、goto againということでdma_alloc_pages() の直前(225行)に戻り、もう一度物理メモリを確保します。この条件とは、「dma_alloc_pages()によって割り当てられた物理メモリの物理バスアドレスが、デバイスで定義されているアドレス範囲(dma_mask)よりも高位なアドレスだった場合」です。

 難しいので、もう少しかみ砕いて説明します。

 DMAはデバイスとメモリが直接通信をするための仕組みです。そのため、デバイスが対応していないバスアドレス範囲の物理アドレスを割り当てられても、DMA通信は行えません。dma_alloc_pages()は、メモリ確保時にはデバイスの対応アドレスを考慮してくれない作りになっていたため、割り当てられたアドレスがデバイスの扱えないものだった場合にリトライする仕組みになっていました。そのリトライ条件が上記条件です。

 この条件に当てはまった場合、最初のトライで割り当てられたアドレスは結果的にデバイスで扱えないアドレスなので、今後もそのデバイスで使うことはありません。つまり、解放してあげる必要があります。それなのにgoto againでリトライしたら、前回dma_alloc_pages()で確保したメモリへのアドレスであるmemoryは、リトライした際のdma_alloc_pages()で確保した新たなメモリへのアドレスに上書きされてしまいます。結果として、以前に取得したメモリは利用できなくなり、メモリはリークします。

 これを糸口にしてカーネルのChangeLogを調査してみると、kernel-2.6.10で修正されていることが分かりました(注5)。RHEL 4はkernel-2.6.9ベースのカーネルで構築されているため、このパッチは取り込まれていません。

 さらに、ccissのデバイスドライバでは、DMAマスクは32bitマスク(4Gbytes)で定義されています。そのため、x86_64かつIOMMU(注6)を持たないCPUで(注7)、物理メモリを4Gbytes以上搭載していると、この事象が発生することになります。今回はx86_64で50Gbytesものメモリを搭載しているため、十分この条件に当てはまりそうです。

 ここまでくれば、話は難しくありません。この処理が何をやっているのかを調べたうえで、改善提案を考えます。

 本来、DMA領域の確保/解放を行うdma_alloc_coherent()という関数は、それほど頻繁に呼び出される関数ではありません。デバイスというものは通常、初期化時にメモリを確保したら、それをいちいち解放したり、また確保したりしないものだからです。

 今回は、SystemTapを仕掛けていた5分間というわずかな時間でさえカーネル内のメモリがリークしていることと、数カ月間にわたって40Gbytes近くもリークし続けていることから考えて、システムの初期化などではなく、何か特殊なメモリの使い方をしていそうです。

 特に、RHEL 4でそれほどのメモリリークが起こる事例報告がなかったことから考えて、商用製品などに含まれている独自のカーネルモジュールが問題を起こしている可能性があります。

 まず見るべきは、カーネルのスタックトレース内にある「ioctl」という単語です。ioctlというのは、ユーザー空間からデバイスの設定などを行うために利用できるインターフェイスで、ioctl自体のインターフェイス設計が何でもありな作りになっていることもあり、問題が起こった際に原因の追跡が難しくなる仕組みです。ioctlから呼び出されているということは、このdma_alloc_coherent()はユーザー空間のプロセスが発行していることになります。

 さて、ここにきて、SystemTapでプロセス名を保存していたことが生きてきます。それによると、発行しているプロセスは「cmaidad」「cmaeventd」の2つでした。ともにPSP(Proliant Support Pack)というHPのデバイスなどを管理するソフトウェア群に含まれるデーモンです。これらはストレージデバイスのチェックなどの目的で、定期的にioctlを発行していますが、今回はその影響でメモリがリークし続け、ついにはリブートへと至っていました。試しにデーモンを停止してみると、確かにメモリのリークは起きなくなりました。やっとのことで、この問題のしっぽを完全につかまえたようです。

注5:http://www.kernel.org/pub/linux/kernel/v2.6/ChangeLog-2.6.10で[PATCH] x86_64: Fallback to swiotlb for dma_alloc_coherentと名前の付いているパッチがそれです。

注6:Input/Output Memory Management Unitの略。仮想アドレス←→物理アドレスの変換を行うMMUの周辺デバイス版です。デバイスアドレスと物理アドレスの変換を行います。各デバイスがアクセスしてよい物理アドレスを設定することができ、デバイスが暴走して無関係なメモリ領域を破壊するのを食い止めることもできます。

注7:arch.x86_64/kernel/pci-gart.cのdma_alloc_coherentはそもそもIOMMUを持たない場合に通るコードになっています。


コラム サルでもできるかもしれない(?)SystemTap

 SystemTapは、RHEL 4ではテクノロジープレビューという形で、自己責任のベータ版のような扱いですが、RHEL 5では正式にサポートされています。ここでは、RHEL 5で簡単にSystemTapを試す方法を紹介します。

 まず、以下のrpmをインストールしてください。

  • systemtap
  • systemtap-runtime
  • kernel-devel
  • kernel-debuginfo

 kernel-debuginfo以外はRHN(Red Hat Network)やインストールCDから入手できます。kernel-debuginfoはhttp://ftp.redhat.com/pub/redhat/linux/enterprise/5Server/en/os/から取得してください。

 次に、下記のような内容のファイルを作ってみてください。

#!/usr/bin/stap
 
probe kernel.function("sys_open") {
  printf("open!(%d)\n", pid())
  print_backtrace()
}

 ここではファイル名をtest.stpとします。

# chmod 755 test.stp
# ./test.stp
open!(3477)
0xffffffff80232785 : sys_open+0x1/0x17
0xffffffff802602f1 : tracesys+0xa7/0xb2
open!(3477)
0xffffffff80232785 : sys_open+0x1/0x17
0xffffffff802602f1 : tracesys+0xa7/0xb2

 これは、システムコールopen(2)の入り口の関数であるsys_open()関数に「open!(<プロセスID>)」という文字列と、カーネルのスタックトレースを出力する関数を埋め込んだものです。この結果から、どのプロセスがopen(2)を発行しているかが分かります。このようにSystemTapを使用すると、普段見えないようなカーネルの挙動が確認できます。さまざまな応用例は開発サイト(http://sourceware.org/systemtap/)にありますので、ぜひのぞいてみてください。


Copyright © ITmedia, Inc. All Rights Reserved.

RSSについて

アイティメディアIDについて

メールマガジン登録

@ITのメールマガジンは、 もちろん、すべて無料です。ぜひメールマガジンをご購読ください。