Thread (1 message) 1 message, 1 author, 2012-01-25

Re: kernel BUG registering cache device

From: Kent Overstreet <hidden>
Date: 2012-01-25 05:37:23

Not sure what that one is. Found another integer overflow bug, but I
don't think that could be causing this problem.

I just uploaded a patch which fixes that overflow and adds a BUG_ON()
which should help narrow it down. Mind giving that one a shot?

On Tue, Jan 24, 2012 at 3:13 AM, Damien Churchill [off-list ref] wrote:
The fix worked perfectly, thanks. I am now able to:

1) create cache device on LVM & register it
2) create backing device on rbd & register it
3) use backing device without attaching the cache perfectly fine
(format as ext4 + mount it and write some files)
4) attach the cache device to the backing device

Unfortunately when trying to mount the backing device after attaching
the cache I end up with a kernel BUG, the syslog output is below.

[  232.762594] bio: create slab <bio-1> at 1
[  232.770175] bcache: btree_journal_read() done
[  232.778854] bcache: btree_check() done
[  232.778867] bcache: journal replay done, 1 keys in 1 entries, seq 3-3
[  232.780579] bcache: registered cache device dm-1
[  242.271440] libceph: client0 fsid 58c297c0-018a-4c13-9a21-0140b9fb2f25
[  242.271973] libceph: mon1 10.10.20.1:6789 session established
[  242.277119]  rbd0: unknown partition table
[  242.277236] rbd: rbd0: added with size 0x3e80000000
[  251.360401] bcache: Caching rbd0, looked up UUID
12378985-91b3-4165-b3a6-6657831f050b
[  280.083396] EXT4-fs (bcache0): recovery complete
[  280.083403] EXT4-fs (bcache0): mounted filesystem with ordered data
mode. Opts: (null)
[  283.160575] ------------[ cut here ]------------
[  283.160609] kernel BUG at
/home/dchurchill/Packages/oneiric/linux/linux-3.2.0~bcache/include/linux/scatterlist.h:63!
[  283.162338] invalid opcode: 0000 [#1] SMP
[  283.164064] CPU 0
[  283.164076] Modules linked in: bnep rfcomm bluetooth
ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE
iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state
nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp
iptable_filter ip_tables x_tables parport_pc ppdev kvm_intel kvm
snd_hda_codec_hdmi snd_hda_codec_realtek eeepc_wmi asus_wmi
sparse_keymap dm_multipath binfmt_misc bridge stp psmouse
snd_hda_intel snd_hda_codec snd_hwdep snd_pcm serio_raw snd_seq_midi
snd_rawmidi snd_seq_midi_event snd_seq radeon ttm snd_timer
snd_seq_device mei(C) drm_kms_helper drm i2c_algo_bit video snd
mac_hid soundcore snd_page_alloc wmi rbd libceph lp parport usbhid hid
e1000e btrfs zlib_deflate firewire_ohci pata_marvell r8169
firewire_core crc_itu_t libcrc32c
[  283.175414]
[  283.177376] Pid: 4222, comm: ext4lazyinit Tainted: G         C
3.2.0-9-generic #17~oneiric2 System manufacturer System Product
Name/P8H67-M EVO
[  283.179432] RIP: 0010:[<ffffffff812f3588>]  [<ffffffff812f3588>]
blk_rq_map_sg+0x178/0x350
[  283.181502] RSP: 0018:ffff8803f01f99d0  EFLAGS: 00010006
[  283.183562] RAX: 0000000000000000 RBX: ffff8803f5019020 RCX: 4acfa4aaf8e1e9bf
[  283.185635] RDX: 0000000000000001 RSI: 00000000d6679dfb RDI: ffff8803f5019000
[  283.187711] RBP: ffff8803f01f9a30 R08: 0000000000000000 R09: ffff8803eeb49e40
[  283.189786] R10: 0000000000000001 R11: 0000000000000001 R12: ffff8803f561c800
[  283.191858] R13: 000000008a430cfb R14: ffff8803f561c810 R15: 0000000000000082
[  283.193941] FS:  0000000000000000(0000) GS:ffff88043f400000(0000)
knlGS:0000000000000000
[  283.196022] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  283.198100] CR2: 0000000001b1d278 CR3: 0000000001c05000 CR4: 00000000000406f0
[  283.200191] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  283.202284] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  283.204382] Process ext4lazyinit (pid: 4222, threadinfo
ffff8803f01f8000, task ffff8803f57a2e20)
[  283.206504] Stack:
[  283.208584]  ffff880400000001 ffff8803f57bb870 ffff8803f5019000
0100000000000001
[  283.210686]  ffff8804213a3368 ffff8803eeb49e40 ffff8803f01f9a30
ffff8803f54f9158
[  283.212778]  ffff8803f57bb870 0000000000000001 0000000000000020
ffff880424e96800
[  283.214833] Call Trace:
[  283.216848]  [<ffffffff81442011>] scsi_init_sgtable+0x41/0x70
[  283.218894]  [<ffffffff8144207d>] scsi_init_io+0x3d/0x150
[  283.220930]  [<ffffffff8144228a>] scsi_setup_fs_cmnd.part.34+0x5a/0x90
[  283.222942]  [<ffffffff814422ef>] scsi_setup_fs_cmnd+0x2f/0x40
[  283.224918]  [<ffffffff8145f62f>] sd_prep_fn+0xaf/0xaf0
[  283.226882]  [<ffffffff813017f4>] ? cfq_dispatch_request+0x64/0xa0
[  283.228835]  [<ffffffff812eecda>] blk_peek_request+0xba/0x240
[  283.230784]  [<ffffffff814427e8>] scsi_request_fn+0x58/0x4c0
[  283.232727]  [<ffffffff812e7c73>] ? __elv_add_request+0x1b3/0x290
[  283.234668]  [<ffffffff812ef590>] blk_queue_bio+0x290/0x380
[  283.236611]  [<ffffffff812ec114>] generic_make_request.part.50+0x74/0xb0
[  283.238570]  [<ffffffff812ec528>] generic_make_request+0x68/0x70
[  283.240517]  [<ffffffff812ec5b5>] submit_bio+0x85/0x110
[  283.242434]  [<ffffffff811ac61a>] ? bio_alloc_bioset+0xba/0x100
[  283.244332]  [<ffffffff812f4900>] blkdev_issue_zeroout+0x110/0x170
[  283.246223]  [<ffffffff8121163b>] ext4_init_inode_table+0x15b/0x370
[  283.248070]  [<ffffffff8166ef75>] ? schedule_timeout+0x175/0x320
[  283.249887]  [<ffffffff81224c65>] ext4_run_li_request+0x85/0xe0
[  283.251686]  [<ffffffff81224d5c>] ext4_lazyinit_thread+0x9c/0x1c0
[  283.253478]  [<ffffffff81224cc0>] ? ext4_run_li_request+0xe0/0xe0
[  283.255273]  [<ffffffff8108832c>] kthread+0x8c/0xa0
[  283.257048]  [<ffffffff8167b034>] kernel_thread_helper+0x4/0x10
[  283.258824]  [<ffffffff810882a0>] ? flush_kthread_worker+0xa0/0xa0

On 24 January 2012 03:24, Kent Overstreet [off-list ref] wrote:
quoted
New code up, should be fixed.

On Mon, Jan 23, 2012 at 4:33 AM, Damien Churchill [off-list ref] wrote:
quoted
Cool thanks, let me know when there's something to test and I'll let
you know how it goes.

On 23 January 2012 12:09, Kent Overstreet [off-list ref] wrote:
quoted
So, we called a null function pointer. Looks like I broke the ioctl
handler somehow, I'll check that out tomorrow.

On Mon, Jan 23, 2012 at 3:52 AM, Damien Churchill [off-list ref] wrote:
quoted
Excellent thanks a lot Kent, that's fixed the problem with the lv cache device.

I am experiencing a problem attempting to use a rbd as a backing
device also. This was working in 3.1 partially so I'm not sure what's
changed there. The following is output to console & syslog whenever
the bcache0 device is accessed by something. Well by blkid or
mkfs.ext4.

Jan 23 11:49:29 dev1 kernel: [  280.993416] BUG: unable to handle
kernel NULL pointer dereference at           (null)
Jan 23 11:49:29 dev1 kernel: [  280.995317] IP: [<          (null)>]
       (null)
Jan 23 11:49:29 dev1 kernel: [  280.997180] PGD 401b0d067 PUD 3fbfa1067 PMD 0
Jan 23 11:49:29 dev1 kernel: [  280.999034] Oops: 0010 [#2] SMP
Jan 23 11:49:29 dev1 kernel: [  281.000831] CPU 2
Jan 23 11:49:29 dev1 kernel: [  281.000843] Modules linked in: bnep
rfcomm bluetooth ip6table_filter ip6_tables ebtable_nat ebtables
ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4
xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp
iptable_filter ip_tables x_tables kvm_intel kvm parport_pc ppdev
binfmt_misc usbhid hid snd_hda_codec_hdmi snd_hda_codec_realtek bridge
stp snd_seq_midi psmouse eeepc_wmi radeon ttm drm_kms_helper asus_wmi
snd_rawmidi drm sparse_keymap snd_seq_midi_event snd_hda_intel
snd_hda_codec snd_hwdep snd_pcm snd_seq snd_timer snd_seq_device snd
mac_hid video serio_raw soundcore dm_multipath wmi i2c_algo_bit
snd_page_alloc mei(C) rbd libceph lp parport firewire_ohci
firewire_core btrfs pata_marvell crc_itu_t e1000e r8169 zlib_deflate
libcrc32c
Jan 23 11:49:29 dev1 kernel: [  281.012308]
Jan 23 11:49:29 dev1 kernel: [  281.014277] Pid: 4152, comm: blkid
Tainted: G      D  C   3.2.0-9-generic #17~oneiric1 System
manufacturer System Product Name/P8H67-M EVO
Jan 23 11:49:29 dev1 kernel: [  281.016330] RIP:
0010:[<0000000000000000>]  [<          (null)>]           (null)
Jan 23 11:49:29 dev1 kernel: [  281.018364] RSP: 0018:ffff8803fbc3de60
 EFLAGS: 00010282
Jan 23 11:49:29 dev1 kernel: [  281.020397] RAX: ffffffffa00763a0 RBX:
0000000000005331 RCX: 0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.022447] RDX: 0000000000005331 RSI:
000000000000101d RDI: ffff880423649380
Jan 23 11:49:29 dev1 kernel: [  281.024502] RBP: ffff8803fbc3de68 R08:
0000000000005331 R09: 000000000000101d
Jan 23 11:49:29 dev1 kernel: [  281.026563] R10: 00007fff9286b990 R11:
0000000000000246 R12: 00000000ffffffe7
Jan 23 11:49:29 dev1 kernel: [  281.028628] R13: 0000000000000000 R14:
ffff8804236496c0 R15: ffff880420abd800
Jan 23 11:49:29 dev1 kernel: [  281.030698] FS:
00007f62be453760(0000) GS:ffff88043f500000(0000)
knlGS:0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.032772] CS:  0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Jan 23 11:49:29 dev1 kernel: [  281.034832] CR2: 0000000000000000 CR3:
00000003fa2da000 CR4: 00000000000406e0
Jan 23 11:49:29 dev1 kernel: [  281.036908] DR0: 0000000000000000 DR1:
0000000000000000 DR2: 0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.038972] DR3: 0000000000000000 DR6:
00000000ffff0ff0 DR7: 0000000000000400
Jan 23 11:49:29 dev1 kernel: [  281.041019] Process blkid (pid: 4152,
threadinfo ffff8803fbc3c000, task ffff8803faa18000)
Jan 23 11:49:29 dev1 kernel: [  281.043083] Stack:
Jan 23 11:49:29 dev1 kernel: [  281.045138]  ffffffff8141fa0f
ffff8803fbc3dec8 ffffffff812f5110 0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.047243]  ffff8804236496c0
0000000000000000 000000004f1d4903 00000000329f0436
Jan 23 11:49:29 dev1 kernel: [  281.049312]  0000000000000003
ffff8804217ad3c0 ffff880404ae0a50 0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.051352] Call Trace:
Jan 23 11:49:29 dev1 kernel: [  281.053334]  [<ffffffff8141fa0f>] ?
ioctl_dev+0x2f/0x40
Jan 23 11:49:29 dev1 kernel: [  281.055284]  [<ffffffff812f5110>]
blkdev_ioctl+0x2e0/0x740
Jan 23 11:49:29 dev1 kernel: [  281.057191]  [<ffffffff811acf10>]
block_ioctl+0x40/0x50
Jan 23 11:49:29 dev1 kernel: [  281.059056]  [<ffffffff8118843a>]
do_vfs_ioctl+0x8a/0x340
Jan 23 11:49:29 dev1 kernel: [  281.060888]  [<ffffffff8117b2ea>] ?
sys_newfstat+0x2a/0x40
Jan 23 11:49:29 dev1 kernel: [  281.062687]  [<ffffffff81188781>]
sys_ioctl+0x91/0xa0
Jan 23 11:49:29 dev1 kernel: [  281.064478]  [<ffffffff81678ec2>]
system_call_fastpath+0x16/0x1b
Jan 23 11:49:29 dev1 kernel: [  281.066259] Code:  Bad RIP value.
Jan 23 11:49:29 dev1 kernel: [  281.068035] RIP  [<          (null)>]
        (null)
Jan 23 11:49:29 dev1 kernel: [  281.069812]  RSP <ffff8803fbc3de60>
Jan 23 11:49:29 dev1 kernel: [  281.071573] CR2: 0000000000000000
Jan 23 11:49:29 dev1 kernel: [  281.073342] ---[ end trace 644c98d7f838705d ]---


On 21 January 2012 08:15, Kent Overstreet [off-list ref] wrote:
quoted
just tracked down a bug I was seeing when I was testing bcache on arm.

Turns out whoever wrote bio_get_nr_vecs() never heard of integer overflow.

But I bet it's the same bug you were seeing, and there's a trivial
workaround in bcache.

Patch will be up momentarily.

On Fri, Jan 20, 2012 at 6:43 PM, Kent Overstreet
[off-list ref] wrote:
quoted
Have you tried the bcache (3.1 based) branch with the same setup? Did
it occur there?

On Fri, Jan 20, 2012 at 3:27 AM, Damien Churchill [off-list ref] wrote:
quoted
Hi there,

I'm receiving the following after attempting to register a cache
device, I've built the kernel using the Ubuntu Precise kernel with a
patch from bcache-3.2-dev applied to the tree.

The cache device was created by running:
$ make-bcache -C -w 2k -b 1M /dev/sysvg/bcache-test

The cache device is a logical volume, I'm unsure if that will have an impact?

Regards,
Damien

Jan 20 11:24:36 dev1 kernel: [  119.025724] bio: create slab <bio-1> at 1
Jan 20 11:24:36 dev1 kernel: [  119.025902] bcache: invalidating existing data
Jan 20 11:24:36 dev1 kernel: [  119.026324] ------------[ cut here ]------------
Jan 20 11:24:36 dev1 kernel: [  119.026341] kernel BUG at
/home/dchurchill/Packages/oneiric/linux/linux-3.2.0~bcache/include/linux/scatterlist.h:63!
Jan 20 11:24:36 dev1 kernel: [  119.026367] invalid opcode: 0000 [#1] SMP
Jan 20 11:24:36 dev1 kernel: [  119.026380] CPU 0
Jan 20 11:24:36 dev1 kernel: [  119.026385] Modules linked in: rfcomm
bnep bluetooth ip6table_filter ip6_tables ebtable_nat ebtables
ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4
xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp
iptable_filter ip_tables x_tables kvm_intel kvm parport_pc ppdev
snd_hda_codec_hdmi snd_hda_codec_realtek binfmt_misc bridge usbhid hid
psmouse snd_hda_intel stp snd_hda_codec snd_hwdep snd_pcm snd_seq_midi
eeepc_wmi asus_wmi sparse_keymap radeon ttm drm_kms_helper drm wmi
mac_hid serio_raw video snd_rawmidi snd_seq_midi_event mei(C) snd_seq
snd_timer snd_seq_device snd i2c_algo_bit soundcore dm_multipath
snd_page_alloc rbd libceph lp parport firewire_ohci firewire_core
crc_itu_t e1000e pata_marvell r8169 btrfs zlib_deflate libcrc32c
Jan 20 11:24:36 dev1 kernel: [  119.026612]
Jan 20 11:24:36 dev1 kernel: [  119.026617] Pid: 2420, comm: bash
Tainted: G         C   3.2.0-9-generic #17~oneiric1 System
manufacturer System Product Name/P8H67-M EVO
Jan 20 11:24:36 dev1 kernel: [  119.026649] RIP:
0010:[<ffffffff812f3588>]  [<ffffffff812f3588>]
blk_rq_map_sg+0x178/0x350
Jan 20 11:24:36 dev1 kernel: [  119.027607] RSP: 0018:ffff880420fbf7c8
 EFLAGS: 00010002
Jan 20 11:24:36 dev1 kernel: [  119.028564] RAX: 0000000000000000 RBX:
ffff8803fa608a20 RCX: 2700013524000135
Jan 20 11:24:36 dev1 kernel: [  119.029529] RDX: 0000000000000011 RSI:
0000000027000135 RDI: ffff8803fa608a00
Jan 20 11:24:36 dev1 kernel: [  119.030492] RBP: ffff880420fbf828 R08:
0000000000001000 R09: ffff880421862f00
Jan 20 11:24:36 dev1 kernel: [  119.031455] R10: 0000000000000001 R11:
0000000000000001 R12: ffff8803fa60a510
Jan 20 11:24:36 dev1 kernel: [  119.032417] R13: 0000000027000135 R14:
ffff8803fa60a520 R15: 00000000000000d3
Jan 20 11:24:36 dev1 kernel: [  119.033385] FS:
00007f5259391720(0000) GS:ffff88043f400000(0000)
knlGS:0000000000000000
Jan 20 11:24:36 dev1 kernel: [  119.034361] CS:  0010 DS: 0000 ES:
0000 CR0: 000000008005003b
Jan 20 11:24:36 dev1 kernel: [  119.035336] CR2: 00007f6d332e8000 CR3:
0000000401c16000 CR4: 00000000000406f0
Jan 20 11:24:36 dev1 kernel: [  119.036310] DR0: 0000000000000000 DR1:
0000000000000000 DR2: 0000000000000000
Jan 20 11:24:36 dev1 kernel: [  119.037287] DR3: 0000000000000000 DR6:
00000000ffff0ff0 DR7: 0000000000000400
Jan 20 11:24:36 dev1 kernel: [  119.038266] Process bash (pid: 2420,
threadinfo ffff880420fbe000, task ffff880403b3dc40)
Jan 20 11:24:36 dev1 kernel: [  119.039252] Stack:
Jan 20 11:24:36 dev1 kernel: [  119.040220]  0000000000000011
ffff880400fcd2b0 ffff8803fa608800 0100000000000001
Jan 20 11:24:36 dev1 kernel: [  119.041196]  ffff8804213a3368
ffff880421862f00 ffff880420fbf828 ffff8804209cb858
Jan 20 11:24:36 dev1 kernel: [  119.042171]  ffff880400fcd2b0
0000000000000001 0000000000000020 ffff880424e96800
Jan 20 11:24:36 dev1 kernel: [  119.043130] Call Trace:
Jan 20 11:24:36 dev1 kernel: [  119.044070]  [<ffffffff81442521>]
scsi_init_sgtable+0x41/0x70
Jan 20 11:24:36 dev1 kernel: [  119.045036]  [<ffffffff8144258d>]
scsi_init_io+0x3d/0x150
Jan 20 11:24:36 dev1 kernel: [  119.045983]  [<ffffffff8144279a>]
scsi_setup_fs_cmnd.part.34+0x5a/0x90
Jan 20 11:24:36 dev1 kernel: [  119.046917]  [<ffffffff814427ff>]
scsi_setup_fs_cmnd+0x2f/0x40
Jan 20 11:24:36 dev1 kernel: [  119.047837]  [<ffffffff8145fb3f>]
sd_prep_fn+0xaf/0xaf0
Jan 20 11:24:36 dev1 kernel: [  119.048747]  [<ffffffff813017f4>] ?
cfq_dispatch_request+0x64/0xa0
Jan 20 11:24:36 dev1 kernel: [  119.049654]  [<ffffffff812eecda>]
blk_peek_request+0xba/0x240
Jan 20 11:24:36 dev1 kernel: [  119.050558]  [<ffffffff81442cf8>]
scsi_request_fn+0x58/0x4c0
Jan 20 11:24:36 dev1 kernel: [  119.051461]  [<ffffffff812e7c73>] ?
__elv_add_request+0x1b3/0x290
Jan 20 11:24:36 dev1 kernel: [  119.052361]  [<ffffffff812ef590>]
blk_queue_bio+0x290/0x380
Jan 20 11:24:36 dev1 kernel: [  119.053262]  [<ffffffff812ec114>]
generic_make_request.part.50+0x74/0xb0
Jan 20 11:24:36 dev1 kernel: [  119.054170]  [<ffffffff812ec528>]
generic_make_request+0x68/0x70
--
To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help