Out of memory and no killable processes... のカーネルパニックを起こしたい (2) - netfilter のフックを利用する編

hiboma.hatenadiary.jp

前回の続き

割り込みコンテキスト

前回はバグったカーネルモジュールを書いて、カーネルモジュールの初期化フェーズでバグったコードを実行してカーネルパニックを起こした。

プロセスコンテキストでバグを起こすのに なんかしっくりこない感じがあるので、{ 割り込み, top half, bottom half } の中で異常を起こしてみたい

netfilter のフック

ネットワーク越しに何かパケットやデータグラムを受け取った際に、カーネル内で任意のコードを実行できないかを考えてみた。iptables の拡張を書く方法を調べたりもしたが、iptables パッケージのビルドとカーネルモジュールのビルドが必要で少し面倒。

1枚のカーネルモジュールだけで作るには下記のエントリを参考にしたところ楽に実装できた

blog.mono0x.net

netfilter のフックを利用して「パケットがきたら foo bar」するといったファイヤウォールのような機能がつくれるらしい

検証環境

macOS + VirtualBox + CentOS7.4 (1708)

検証 Vagrantfile

# -*- mode: ruby -*-
# vi: set ft=ruby :

# All Vagrant configuration is done below. The "2" in Vagrant.configure
# configures the configuration version (we support older styles for
# backwards compatibility). Please don't change it unless you know what
# you're doing.
Vagrant.configure("2") do |config|
  config.vm.box = "centos/7"
  config.vm.network :private_network, ip:"192.168.33.100"
  config.vm.provider "virtualbox" do |vb|
    vb.gui = true
    vb.customize ["modifyvm", :id, "--memory", "512", "--cpus", "4", "--ioapic", "on"]
    vb.customize ["modifyvm", :id, "--uart1", "0x3F8", "4"]
    vb.customize ["modifyvm", :id, "--uartmode1", "file", "/tmp/vagrant-ttyS0.log"]
  end
end

実装例

先のブログのコードを真似て少し改造して、IPv4 + UDP で 10000番ポートにデータグラムを送ると kmem_cache_alloc + GFP_ATOMIC を無限ループで実行するカーネルモジュールとした。

TCP だと connect(2) の段階の 3way-handshake の段階でコードが動いてしまい検証がやりにくいので、システムコールの呼び出しとデータの送信が 1対1 で分かりやすいように UDPのデータグラムで動くようにした。その点では ICMP でもよさそうだけど 、ま 何だっていいのだ

udppanic.c

バグを埋め込むだけなら書ける 💀

#include <linux/module.h>
#include <linux/mm.h>
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/ip.h>
#include <linux/inet.h>
#include <linux/netfilter_ipv4.h>
#include <linux/udp.h>

MODULE_DESCRIPTION("alloc_pages test");
MODULE_AUTHOR("hiroya");
MODULE_LICENSE("GPL");

static struct kmem_cache *cache;
struct foo_bar {
    char name[1000];
};

static unsigned int handle_hook(const struct nf_hook_ops *ops,
                struct sk_buff *skb,
                const struct net_device *in,
                const struct net_device *out,
#ifndef __GENKSYMS__
        const struct nf_hook_state *state
#else
                int (*okfn)(struct sk_buff*)
#endif
)
{
    struct iphdr *iph = ip_hdr(skb);
    struct udphdr *udph;
    struct foo_bar *foo;

    if (!iph) {
        return NF_ACCEPT;
    }

    if (iph->version != 4 || iph->protocol != IPPROTO_UDP) {
        return NF_ACCEPT;
    }

    udph = udp_hdr(skb);
    if (udph->dest != htons(10000)) {
        return NF_ACCEPT;
    }

    /* oops */
    for (;;) {
        foo = (struct foo_bar *)kmem_cache_alloc(cache, GFP_ATOMIC);
        if (!foo)
              return NF_ACCEPT;
    }

    /* never */
    return NF_ACCEPT;
}

static struct nf_hook_ops hook_ops = {
    .hook     = handle_hook,
    .pf       = PF_INET,
    .hooknum  = NF_INET_LOCAL_IN,
    .priority = NF_IP_PRI_FILTER,
};

static int __init alloc_pages_init(void)
{
    int err;
    cache = kmem_cache_create("udppanic",
                          sizeof(struct foo_bar),
                          0, SLAB_PANIC, NULL);
    if (!cache)
            return -ENOMEM;

    err = nf_register_hook(&hook_ops);
    if (err < 0) {
        kmem_cache_destroy(cache);
        return err;
    }

    return 0;
}

static void  __exit alloc_pages_exit(void) {
    kmem_cache_destroy(cache);
    nf_unregister_hook(&hook_ops);
}

module_init(alloc_pages_init);
module_exit(alloc_pages_exit);

余談 10000 番ポートで LISTEN するプロセスがいないまま UDP データグラムを受け取っても、このコードは実行される

Makefile

obj-m := udppanic.o
KDIR := /lib/modules/$(shell uname -r)/build
PWD := $(shell pwd)
default:
    $(MAKE) -C $(KDIR) SUBDIRS=$(PWD) modules

insmod:
    insmod udppanic.ko

rmmod:
    rmmod udppanic.ko

reload:
    -make rmmod
    make insmod

検証の手順

カーネルモジュールを make と insmod した後に、ホストOSから rubyワンライナーVMUDP データグラムを飛ばす (注: nc を使ってもよいが、応答待ちでブロックし続けてしまうケースがあるので、一方的に投げつけるだけのワンライナー Ruby とした )

$ ruby -rsocket -e 'u = UDPSocket.new; u.connect("192.168.33.100", 10000); u.send "hello", 0 '

VM がデータグラムを受けとると先のカーネルモジュールのバグったコードが実行され、 dmesg に SLUB: Unable to allocate memory on node -1 のメッセージやコールトレースを出す。

[  109.665164] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  ------------   3.10.0-693.2.2.el7.x86_64 #1
[  109.665165] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  109.665166]  0000000000204020 1e6d2387f43adc34 ffff88001fc03678 ffffffff816a3db1
[  109.665169]  ffff88001fc03708 ffffffff81188810 0000000000000010 0000000000000000
[  109.665171]  ffffffffffffffff 0020402000000000 0000000000000001 1e6d2387f43adc34
[  109.665173] Call Trace:
[  109.665174]  <IRQ>  [<ffffffff816a3db1>] dump_stack+0x19/0x1b
[  109.665182]  [<ffffffff81188810>] warn_alloc_failed+0x110/0x180
[  109.665184]  [<ffffffff8169fd8a>] __alloc_pages_slowpath+0x6b6/0x724
[  109.665187]  [<ffffffff8105a353>] ? x2apic_send_IPI_mask+0x13/0x20
[  109.665189]  [<ffffffff8118cd85>] __alloc_pages_nodemask+0x405/0x420
[  109.665191]  [<ffffffff811d1108>] alloc_pages_current+0x98/0x110
[  109.665193]  [<ffffffff811dbe8c>] new_slab+0x2fc/0x310
[  109.665195]  [<ffffffff811dd71c>] ___slab_alloc+0x3ac/0x4f0
[  109.665197]  [<ffffffffc033a061>] ? handle_hook+0x61/0x76 [udppanic]
[  109.665199]  [<ffffffffc033a061>] ? handle_hook+0x61/0x76 [udppanic]
[  109.665201]  [<ffffffff816a10ee>] __slab_alloc+0x40/0x5c
[  109.665203]  [<ffffffff811df6b3>] kmem_cache_alloc+0x193/0x1e0
[  109.665204]  [<ffffffffc033a061>] handle_hook+0x61/0x76 [udppanic] 🔥
[  109.665207]  [<ffffffff815bfe80>] nf_iterate+0x70/0xb0
[  109.665209]  [<ffffffff815bff68>] nf_hook_slow+0xa8/0x110
[  109.665211]  [<ffffffff815ca3b2>] ip_local_deliver+0xb2/0xd0
[  109.665212]  [<ffffffff815c9fc0>] ? ip_rcv_finish+0x350/0x350
[  109.665214]  [<ffffffff815c9cfa>] ip_rcv_finish+0x8a/0x350
[  109.665215]  [<ffffffff815ca686>] ip_rcv+0x2b6/0x410
[  109.665219]  [<ffffffff810d1223>] ? find_busiest_group+0x143/0x980
[  109.665221]  [<ffffffff81586f22>] __netif_receive_skb_core+0x572/0x7c0
[  109.665224]  [<ffffffff810ea8ca>] ? __getnstimeofday64+0x3a/0xd0
[  109.665225]  [<ffffffff81587188>] __netif_receive_skb+0x18/0x60
[  109.665227]  [<ffffffff81587210>] netif_receive_skb_internal+0x40/0xc0
[  109.665229]  [<ffffffff81588318>] napi_gro_receive+0xd8/0x130
[  109.665233]  [<ffffffffc038d47c>] e1000_clean_rx_irq+0x2ac/0x4f0 [e1000]
[  109.665235]  [<ffffffffc038ded8>] e1000_clean+0x278/0x8d0 [e1000]
[  109.665237]  [<ffffffff8158799d>] net_rx_action+0x16d/0x380
[  109.665240]  [<ffffffff81090b3f>] __do_softirq+0xef/0x280
[  109.665242]  [<ffffffff816b6a9c>] call_softirq+0x1c/0x30
[  109.665245]  [<ffffffff8102d3c5>] do_softirq+0x65/0xa0
[  109.665246]  [<ffffffff81090ec5>] irq_exit+0x105/0x110
[  109.665248]  [<ffffffff816b7636>] do_IRQ+0x56/0xe0
[  109.665250]  [<ffffffff816ac22d>] common_interrupt+0x6d/0x6d
[  109.665251]  <EOI>  [<ffffffff816ab4c6>] ? native_safe_halt+0x6/0x10
[  109.665254]  [<ffffffff816ab35e>] default_idle+0x1e/0xc0
[  109.665256]  [<ffffffff81035006>] arch_cpu_idle+0x26/0x30
[  109.665257]  [<ffffffff810e7bca>] cpu_startup_entry+0x14a/0x1c0
[  109.665260]  [<ffffffff81692c77>] rest_init+0x77/0x80
[  109.665262]  [<ffffffff81b45060>] start_kernel+0x439/0x45a
[  109.665264]  [<ffffffff81b44a30>] ? repair_env_string+0x5c/0x5c
[  109.665266]  [<ffffffff81b44120>] ? early_idt_handler_array+0x120/0x120
[  109.665268]  [<ffffffff81b445ef>] x86_64_start_reservations+0x24/0x26
[  109.665269]  [<ffffffff81b44740>] x86_64_start_kernel+0x14f/0x172
[  109.665271] SLUB: Unable to allocate memory on node -1 (gfp=0x20) 🔥
[  109.665272]   cache: udppanic, object size: 1000, buffer size: 1000, default order: 2, min order: 0
[  109.665273]   node 0: slabs: 16698, objs: 258960, free: 0

kmem_cache_alloc に GFP_ATOMIC を指定しているので、この段階ではアロケートに失敗しているだけで まだカーネルパニックではない。

slabtop で slab の統計を見ると udppanic の slab (slub?) が上位に現れている。こいつが VM のメモリを蝕んでいくわけだな

 Active / Total Objects (% used)    : 894841 / 913748 (97.9%)
 Active / Total Slabs (% used)      : 48416 / 48416 (100.0%)
 Active / Total Caches (% used)     : 68 / 102 (66.7%)
 Active / Total Size (% used)       : 390934.60K / 395103.05K (98.9%)
 Minimum / Average / Maximum Object : 0.01K / 0.43K / 8.00K

  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME                   
361800 361800 100%    0.98K  41727   16    667632K udppanic 🍣
129370 129370 100%    0.02K    761  170  3044K scsi_data_buffer
123776 123776 100%    0.03K    967  128  3868K kmalloc-32
 82944  82944 100%    0.01K    162  512   648K kmalloc-8
 58112  58112 100%    0.02K    227  256   908K kmalloc-16
 46720  41176  88%    0.06K    730   64  2920K kmalloc-64
 18870  15701  83%    0.04K    185  102   740K selinux_inode_security

カーネルパニックさせる

ワンライナーを loop させてデータグラムを延々と送りつけるとどうなるか?

$ ruby -rsocket -e 'u = UDPSocket.new; u.connect("192.168.33.100", 10000); loop{ u.send "hello", 0 }'

VMOut of memory and no killable processes...カーネルパニックした

[  246.368414] Kernel panic - not syncing: Out of memory and no killable processes... 🔥💀
[  246.368414] 
[  246.435193] CPU: 2 PID: 949 Comm: sshd Tainted: G           OE  ------------   3.10.0-693.2.2.el7.x86_64 #1
[  246.494941] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  246.522685]  0000000000000000 000000002fd3deb3 ffff88001b9af810 ffffffff816a3db1
[  246.567516]  ffff88001b9af890 ffffffff8169dc74 ffffffff00000008 ffff88001b9af8a0
[  246.619360]  ffff88001b9af840 000000002fd3deb3 0000000000000000 ffff88001edd3600
[  246.631261] Call Trace:
[  246.638255]  [<ffffffff816a3db1>] dump_stack+0x19/0x1b
[  246.654648]  [<ffffffff8169dc74>] panic+0xe8/0x20d
[  246.672046]  [<ffffffff81186c0a>] out_of_memory+0x4ea/0x4f0
[  246.678707]  [<ffffffff8169fcaa>] __alloc_pages_slowpath+0x5d6/0x724
[  246.699236]  [<ffffffff8118cd85>] __alloc_pages_nodemask+0x405/0x420
[  246.708545]  [<ffffffff811d4135>] alloc_pages_vma+0xb5/0x200
[  246.731750]  [<ffffffff811c453d>] read_swap_cache_async+0xed/0x160
[  246.739205]  [<ffffffff811c4658>] swapin_readahead+0xa8/0x110
[  246.746908]  [<ffffffff811b235b>] handle_mm_fault+0xadb/0xfa0
[  246.769216]  [<ffffffff811de591>] ? __slab_free+0x81/0x2f0
[  246.802331]  [<ffffffff816afff4>] __do_page_fault+0x154/0x450
[  246.829858]  [<ffffffff816b0325>] do_page_fault+0x35/0x90
[  246.847046]  [<ffffffff816ac548>] page_fault+0x28/0x30
[  246.881244]  [<ffffffff81331e45>] ? __clear_user+0x25/0x50
[  246.920392]  [<ffffffff810363d3>] save_xstate_sig+0x123/0x1c0
[  246.928347]  [<ffffffff8102a879>] do_signal+0x469/0x6c0
[  246.932701]  [<ffffffff8102ab2f>] do_notify_resume+0x5f/0xb0
[  246.943045]  [<ffffffff816b52bd>] int_signal+0x12/0x17
[  246.969741] Kernel Offset: disabled

やったね めでたし めでたし 😊

失敗した例

kmem_cache_alloc + GFP_KERNEL を指定すると BUG: scheduling while atomic: swapper/0/0/0x10000100 だとか bad: scheduling from the idle thread! の dmesg が出て来る

[  466.084459] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W  OE  ------------   3.10.0-693.2.2.el7.x86_64 #1
[  466.084465] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  466.084471]  ffffffff819e4000 d8d73ee1a1819a51 ffff88001fc039a8 ffffffff816a3db1
[  466.084477]  ffff88001fc039b8 ffffffff8169e222 ffff88001fc03a18 ffffffff816a9417
[  466.084484]  ffffffff819f9480 ffffffff819e7fd8 ffffffff819e7fd8 ffffffff819e7fd8
[  466.084491] Call Trace:
[  466.084496]  <IRQ>  [<ffffffff816a3db1>] dump_stack+0x19/0x1b
[  466.084511]  [<ffffffff8169e222>] __schedule_bug+0x64/0x72
[  466.084518]  [<ffffffff816a9417>] __schedule+0x807/0x8b0
[  466.084526]  [<ffffffff810c13e6>] __cond_resched+0x26/0x30
[  466.084532]  [<ffffffff816a978a>] _cond_resched+0x3a/0x50
[  466.084550]  [<ffffffff811df555>] kmem_cache_alloc+0x35/0x1e0
[  466.084558]  [<ffffffffc02ec061>] ? handle_hook+0x61/0x76 [udppanic]
[  466.084564]  [<ffffffffc02ec061>] handle_hook+0x61/0x76 [udppanic]
[  466.084572]  [<ffffffff815bfe80>] nf_iterate+0x70/0xb0
[  466.084578]  [<ffffffff815bff68>] nf_hook_slow+0xa8/0x110
[  466.084585]  [<ffffffff815ca3b2>] ip_local_deliver+0xb2/0xd0
[  466.084591]  [<ffffffff815c9fc0>] ? ip_rcv_finish+0x350/0x350
[  466.084597]  [<ffffffff815c9cfa>] ip_rcv_finish+0x8a/0x350
[  466.084602]  [<ffffffff815ca686>] ip_rcv+0x2b6/0x410
[  466.084609]  [<ffffffff810d1223>] ? find_busiest_group+0x143/0x980
[  466.084618]  [<ffffffff81586f22>] __netif_receive_skb_core+0x572/0x7c0
[  466.084625]  [<ffffffff810ea8ca>] ? __getnstimeofday64+0x3a/0xd0
[  466.084632]  [<ffffffff81587188>] __netif_receive_skb+0x18/0x60
[  466.084638]  [<ffffffff81587210>] netif_receive_skb_internal+0x40/0xc0
[  466.084645]  [<ffffffff81588318>] napi_gro_receive+0xd8/0x130
[  466.084654]  [<ffffffffc038347c>] e1000_clean_rx_irq+0x2ac/0x4f0 [e1000]
[  466.084661]  [<ffffffffc0383ed8>] e1000_clean+0x278/0x8d0 [e1000]
[  466.084669]  [<ffffffff8158799d>] net_rx_action+0x16d/0x380
[  466.084675]  [<ffffffff81090b3f>] __do_softirq+0xef/0x280
[  466.084682]  [<ffffffff816b6a9c>] call_softirq+0x1c/0x30
[  466.084689]  [<ffffffff8102d3c5>] do_softirq+0x65/0xa0
[  466.084695]  [<ffffffff81090ec5>] irq_exit+0x105/0x110
[  466.084701]  [<ffffffff816b7636>] do_IRQ+0x56/0xe0
[  466.084706]  [<ffffffff816ac22d>] common_interrupt+0x6d/0x6d
[  466.084711]  <EOI>  [<ffffffff816ab4c6>] ? native_safe_halt+0x6/0x10
[  466.084719]  [<ffffffff816ab35e>] default_idle+0x1e/0xc0
[  466.084726]  [<ffffffff81035006>] arch_cpu_idle+0x26/0x30
[  466.084732]  [<ffffffff810e7bca>] cpu_startup_entry+0x14a/0x1c0
[  466.084740]  [<ffffffff81692c77>] rest_init+0x77/0x80
[  466.084748]  [<ffffffff81b45060>] start_kernel+0x439/0x45a
[  466.084755]  [<ffffffff81b44a30>] ? repair_env_string+0x5c/0x5c
[  466.084761]  [<ffffffff81b44120>] ? early_idt_handler_array+0x120/0x120
[  466.084768]  [<ffffffff81b445ef>] x86_64_start_reservations+0x24/0x26
[  466.084774]  [<ffffffff81b44740>] x86_64_start_kernel+0x14f/0x172
[  466.084870] BUG: scheduling while atomic: swapper/0/0/0x10000100 🔥💀

GFP_ATOMIC を指定しているのにスケジューリングしてしまった 割り込みコンテキストでは sleep するような関数呼び出しするな という規約(?) があったな、そうだったなと思い出す

kernel/sched/core.c

/*
 * Print scheduling while atomic bug:
 */
static noinline void __schedule_bug(struct task_struct *prev)
{
    if (oops_in_progress)
        return;

    printk(KERN_ERR "BUG: scheduling while atomic: %s/%d/0x%08x\n", 🔥
        prev->comm, prev->pid, preempt_count());

    debug_show_held_locks(prev);
    print_modules();
    if (irqs_disabled())
        print_irqtrace_events(prev);
    dump_stack();
    add_taint(TAINT_WARN, LOCKDEP_STILL_OK);
}

_cond_resched -> __schedule -> schedule_debug から呼び出されている

感想

  • (壊れた)おもちゃのようなカーネルモジュールだが、割り込みハンドラの延長で呼び出されているのが分かって おもしろい
  • GFP_ATOMIC を指定していてもアロケートが失敗する状況が繰り返されると Out of memory and no killable processes...カーネルパニックを招くことがあるのだと知って なるほどだった
  • 実環境では、急激に slab (やページ)を使いつくすようなバグはまず無いだろうから 特異なケースの検証という気もするが 何かの役にはたつだろう