最近のbtrfsの話(linus head) cleaner の lock とか

最近、うちのbtrfsはよくこういうエラーで死んでいて

% cd /sys/fs/pstore
% cat dmesg-efi-3 dmesg-efi-2 dmesg-efi-1                                                                                                                                                                                                                   
Oops#1 Part3
<3>[16662.858996] [drm:ring_stuck] *ERROR* Kicking stuck wait on render ring
<7>[17728.729197] BTRFS debug (device sde1): unlinked 3 orphans
<7>[17912.803995] BTRFS debug (device sde1): unlinked 8 orphans
<4>[21166.871256] general protection fault: 0000 [#1] SMP 
<4>[21166.871287] Modules linked in: macvtap macvlan ebtables xt_CHECKSUM iptable_mangle hwmon_vid nfsd auth_rpcgss oid_registry nfs_acl lockd sunrpc i915 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel i2c_algo_bit intel_agp intel_gtt drm_kms_helper snd_hda_codec drm agpgart i2c_i801 pata_via
<4>[21166.871414] CPU: 7 PID: 258 Comm: btrfs-cleaner Tainted: G        W    3.11.0-rc1+ #271
<4>[21166.871439] Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 3806 08/20/2012
<4>[21166.871469] task: ffff8805fb0c0000 ti: ffff8805faff0000 task.ti: ffff8805faff0000
<4>[21166.871493] RIP: 0010:[<ffffffff812e70c9>]  [<ffffffff812e70c9>] btrfs_clean_one_deleted_snapshot+0x49/0x150
Oops#1 Part2
<4>[21166.871527] RSP: 0018:ffff8805faff1e70  EFLAGS: 00010283
<4>[21166.871546] RAX: dead000000200200 RBX: ffff880323212458 RCX: 0000000000003b79
<4>[21166.871569] RDX: dead000000100100 RSI: 0000000000000246 RDI: ffff8805fb52c798
<4>[21166.871591] RBP: ffff8805faff1e88 R08: 0000000000000000 R09: 0000000000000001
<4>[21166.871612] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8805fb52c000
<4>[21166.871633] R13: ffff880323212000 R14: ffff8805fb0c0000 R15: 0000000000000000
<4>[21166.871655] FS:  0000000000000000(0000) GS:ffff88061f3c0000(0000) knlGS:0000000000000000
<4>[21166.871680] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[21166.871698] CR2: 000012db7ef1c008 CR3: 000000000ec0c000 CR4: 00000000000427e0
<4>[21166.871719] Stack:
<4>[21166.871730]  ffff8805fb48a800 ffff8805fb0c0000 ffff8805fb0c0000 ffff8805faff1ec8
<4>[21166.871759]  ffffffff812df5d0 0000000000000000 ffff8805fb817a48 ffff8805fb48a800
Oops#1 Part1
<4>[21166.871786]  ffffffff812df4b0 0000000000000000 0000000000000000 ffff8805faff1f48
<4>[21166.871815] Call Trace:
<4>[21166.871829]  [<ffffffff812df5d0>] cleaner_kthread+0x120/0x180
<4>[21166.871847]  [<ffffffff812df4b0>] ? check_leaf.isra.41+0x310/0x310
<4>[21166.871869]  [<ffffffff810aa4d0>] kthread+0xc0/0xd0
<4>[21166.871886]  [<ffffffff810aa410>] ? kthread_create_on_node+0x120/0x120
<4>[21166.871910]  [<ffffffff81703f1c>] ret_from_fork+0x7c/0xb0
<4>[21166.871930]  [<ffffffff810aa410>] ? kthread_create_on_node+0x120/0x120
<4>[21166.871951] Code: 3e 47 41 00 49 8b 9c 24 d8 07 00 00 49 8d 84 24 d8 07 00 00 48 39 c3 0f 84 c5 00 00 00 48 8b 43 08 4c 8d ab a8 fb ff ff 48 8b 13 <48> 89 42 08 48 89 10 48 b8 00 01 10 00 00 00 ad de 48 89 03 48 
<1>[21166.872091] RIP  [<ffffffff812e70c9>] btrfs_clean_one_deleted_snapshot+0x49/0x150
<4>[21166.872117]  RSP <ffff8805faff1e70>
<4>[21166.876524] ---[ end trace fa76c497d23a7946 ]---

まあ、cronでsnapshotをdeleteしているタイミングで(確率的に)死んでるからそのcron jobとめればいいんだけど、それも気持ちわるいので放置してn時間に1回再起動している。

死んでる当該部分は fs/btrfs/transaction.c の

int btrfs_clean_one_deleted_snapshot(struct btrfs_root *root)
{
	int ret;
	struct btrfs_fs_info *fs_info = root->fs_info;

	spin_lock(&fs_info->trans_lock);
	if (list_empty(&fs_info->dead_roots)) {
		spin_unlock(&fs_info->trans_lock);
		return 0;
	}
	root = list_first_entry(&fs_info->dead_roots,
			struct btrfs_root, root_list);
	list_del(&root->root_list);
	spin_unlock(&fs_info->trans_lock);

この list_del のところ。で、 list_delで dumpのRAXとRDXに "dead000000200200" と "dead000000100100" って出ているのでわかる人にはわかるかと思うのだけど、 &root->root_list が list に入ってないのに del_list してることになってる(正確にはlistにいれて消したのにまた消そうとしているはず)

このコードの部分は trans_lockで spinlock されてるし他の部分も

inode.c

			spin_lock(&fs_info->trans_lock);
			list_for_each_entry(dead_root, &fs_info->dead_roots,
					    root_list) {
				if (dead_root->root_key.objectid ==
				    found_key.objectid) {
					is_dead_root = 1;
					break;
				}
			}
			spin_unlock(&fs_info->trans_lock);

transaction.c

int btrfs_add_dead_root(struct btrfs_root *root)
{
	spin_lock(&root->fs_info->trans_lock);
	list_add_tail(&root->root_list, &root->fs_info->dead_roots);
	spin_unlock(&root->fs_info->trans_lock);

ちゃんと trans_lock で lockされてるし、あやしげな

disk-io.c

static void del_fs_roots(struct btrfs_fs_info *fs_info)
{
	int ret;
	struct btrfs_root *gang[8];
	int i;

	while (!list_empty(&fs_info->dead_roots)) {
		gang[0] = list_entry(fs_info->dead_roots.next,
				     struct btrfs_root, root_list);
		list_del(&gang[0]->root_list);

		if (gang[0]->in_radix) {
			btrfs_drop_and_free_fs_root(fs_info, gang[0]);
		} else {
			free_extent_buffer(gang[0]->node);
			free_extent_buffer(gang[0]->commit_root);
			btrfs_put_fs_root(gang[0]);
		}
	}

これも、 open_ctreeとclose_ctreeからだけ呼ばれてこのタイミングでは cleaner スレッドは止まっているはずなので、こことぶつかってることはありえない…(と思う)

そーすると、一体どこがどうなって btrfs_clean_one_deleted_snapshot があんな死に方をしてしまうのかまったくもって謎めいている。なにがどうなってるのやら