Project

General

Profile

Bug #2267

Ceph client crashed after shutting down one mds and osd

Added by Maciej Galkiewicz almost 12 years ago. Updated over 11 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Development
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

Ceph version: 0.44.1-1~bpo70+1
Kernel version: 3.2.12-1

Ceph config:
[global]
auth supported = cephx
keyring = /srv/ceph/keyring.admin

[mon]
mon data = /srv/ceph/mon

[mon.n3c1]
host = n3c1
mon addr = 1.1.1.1:6789
[mon.n8c1]
host = n8c1
mon addr = 2.2.2.2:6789
[mon.n4c1]
host = n4c1
mon addr = 3.3.3.3:6789

[mds]
debug mds = 1
keyring = /srv/ceph/ceph-stage2/keyring.$name

[mds.n3c1]
host = n3c1
mds standby replay = true
mds standby for name = n4c1
[mds.n4c1]
host = n4c1

[osd]
osd data = /srv/ceph/$name
osd journal = /srv/ceph/$name.journal
osd journal size = 1000
filestore btrfs snap = 0
keyring = /srv/ceph/ceph-stage2/keyring.$name
debug osd = 1

[osd.1]
host = n3c1
[osd.0]
host = n4c1

[961187.404239] libceph: osd1 1.1.1.1:6801 socket closed
[961187.405540] libceph: osd1 1.1.1.1:6801 connect authorization failure
[962088.110608] libceph: osd1 1.1.1.1:6801 socket closed
[962088.112420] libceph: osd1 1.1.1.1:6801 connect authorization failure
[962989.108250] libceph: osd1 1.1.1.1:6801 socket closed
[963889.402235] libceph: osd1 1.1.1.1:6801 socket closed
[963889.403419] libceph: osd1 1.1.1.1:6801 connect authorization failure
[965619.703634] libceph: osd1 1.1.1.1:6801 socket closed
[966519.993750] libceph: osd1 1.1.1.1:6801 socket closed
[966519.995090] libceph: osd1 1.1.1.1:6801 connect authorization failure
[967421.107795] libceph: osd1 1.1.1.1:6801 socket closed
[968321.397794] libceph: osd1 1.1.1.1:6801 socket closed
[968321.399122] libceph: osd1 1.1.1.1:6801 connect authorization failure
[972358.945257] libceph: osd1 1.1.1.1:6801 socket closed
[991643.078884] libceph: osd1 1.1.1.1:6801 socket closed
[991643.080226] libceph: osd1 1.1.1.1:6801 connect authorization failure
[1033201.439727] libceph: mon2 1.1.1.1:6804 socket closed
[1033201.439737] libceph: mon2 1.1.1.1:6804 session lost, hunting for new mon
[1033201.443627] libceph: mon0 2.2.2.2:6789 session established
[1033203.977343] libceph: osd1 1.1.1.1:6801 socket closed
[1033203.978001] libceph: osd1 1.1.1.1:6801 connection failed
[1033204.816786] libceph: osd1 1.1.1.1:6801 connection failed
[1033205.816636] libceph: osd1 1.1.1.1:6801 connection failed
[1033207.820595] libceph: osd1 1.1.1.1:6801 connection failed
[1033211.824574] libceph: osd1 1.1.1.1:6801 connection failed
[1033233.190734] libceph: osd1 down
[1033338.949396] libceph: osd1 up
[1033503.993763] libceph: osd1 1.1.1.1:6801 socket closed
[1033503.994352] libceph: osd1 1.1.1.1:6801 connection failed
[1033504.816523] libceph: osd1 1.1.1.1:6801 connection failed
[1033505.816596] libceph: osd1 1.1.1.1:6801 connection failed
[1033507.820580] libceph: osd1 1.1.1.1:6801 connection failed
[1033511.824589] libceph: osd1 1.1.1.1:6801 connection failed
[1033534.730898] libceph: osd1 down
[1033540.401857] libceph: get_reply unknown tid 31773 from osd0
[1034382.461077] libceph: osd1 up
[1034382.768772] BUG: unable to handle kernel NULL pointer dereference at 0000000000000048
[1034382.768785] IP: [<ffffffffa02a1ec8>] con_work+0x14da/0x1d21 [libceph]
[1034382.768798] PGD 2df5067 PUD 2ca0067 PMD 0
[1034382.768805] Oops: 0000 [#1] SMP
[1034382.768811] CPU 0
[1034382.768813] Modules linked in: rmd160 sha1_ssse3 sha1_generic hmac crypto_null camellia lzo cast6 cast5 deflate zlib_deflate cts ctr gcm ccm serpent blowfish_gen
eric blowfish_x86_64 blowfish_common twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common ecb xcbc sha256_generic sha512_generic des_generic xfrm_user ah
6 ah4 esp6 esp4 xfrm4_mode_beet xfrm4_tunnel tunnel4 xfrm4_mode_tunnel xfrm4_mode_transport xfrm6_mode_transport xfrm6_mode_ro xfrm6_mode_beet xfrm6_mode_tunnel ipcom
p ipcomp6 xfrm_ipcomp xfrm6_tunnel tunnel6 rng_core af_key ip6table_filter ip6_tables iptable_filter ip_tables x_tables xfs cryptd aes_x86_64 aes_generic cbc rbd libc
eph crc32c libcrc32c loop ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi scsi_mod nfsd nfs lockd fscach
e auth_rpcgss nfs_acl sunrpc ext3 jbd fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext4 mbcache jbd2 crc16 xen_blkfront xen_netfront
[1034382.768933]
[1034382.768937] Pid: 26554, comm: kworker/0:0 Not tainted 3.2.0-2-amd64 #1
[1034382.768943] RIP: e030:[<ffffffffa02a1ec8>]  [<ffffffffa02a1ec8>] con_work+0x14da/0x1d21 [libceph]
[1034382.768952] RSP: e02b:ffff88007c15bdb0  EFLAGS: 00010246
[1034382.768956] RAX: 0000000000000000 RBX: ffff88007bf9a030 RCX: 0000000000000080
[1034382.768962] RDX: 000000000007f000 RSI: ffff88007b800620 RDI: ffff88007b800618
[1034382.768967] RBP: ffffea00017fe410 R08: 0000000000000000 R09: 0000000000000258
[1034382.768971] R10: 96206c705f02e221 R11: 96206c705f02e221 R12: ffff88007b800580
[1034382.768976] R13: 0000000000000000 R14: 0000000000000000 R15: ffff88007bf9a420
[1034382.768985] FS:  00007fa421c4b7a0(0000) GS:ffff88007ff8b000(0000) knlGS:0000000000000000
[1034382.768990] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[1034382.772572] CR2: 0000000000000048 CR3: 000000000306a000 CR4: 0000000000002660
[1034382.772572] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[1034382.772572] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[1034382.772572] Process kworker/0:0 (pid: 26554, threadinfo ffff88007c15a000, task ffff88007c836f60)
[1034382.772572] Stack:
[1034382.772572]  0000000000000000 ffffffff81003129 ffffffff81006c3f ffff88007c836f60
[1034382.772572]  ffff88007bf9a058 ffffffff00080000 0000000000001000 0000000000080000
[1034382.772572]  ffff88007bf9a1a8 ffff88007bf9a308 ffff88007a9d3e00 ffff880000080000
[1034382.772572] Call Trace:
[1034382.772572]  [<ffffffff81003129>] ? xen_end_context_switch+0xe/0x1c
[1034382.772572]  [<ffffffff81006c3f>] ? xen_restore_fl_direct_reloc+0x4/0x4
[1034382.772572]  [<ffffffffa02a09ee>] ? read_partial_message_section.isra.17+0x74/0x74 [libceph]
[1034382.772572]  [<ffffffff8105ae4d>] ? process_one_work+0x163/0x284
[1034382.772572]  [<ffffffff8105be15>] ? worker_thread+0xc2/0x145
[1034382.772572]  [<ffffffff8105bd53>] ? manage_workers.isra.23+0x15b/0x15b
[1034382.772572]  [<ffffffff8105ef51>] ? kthread+0x76/0x7e
[1034382.772572]  [<ffffffff81348834>] ? kernel_thread_helper+0x4/0x10
[1034382.772572]  [<ffffffff813468f3>] ? int_ret_from_sys_call+0x7/0x1b
[1034382.772572]  [<ffffffff81341a3c>] ? retint_restore_args+0x5/0x6
[1034382.772572]  [<ffffffff81348830>] ? gs_change+0x13/0x13
[1034382.772572] Code: 89 ef e8 d7 df ff ff e9 97 00 00 00 49 83 bc 24 90 00 00 00 00 74 4c 4d 63 84 24 a0 00 00 00 49 8b 84 24 98 00 00 00 49 c1 e0 04 <4c> 03 40 48 
31 c0 45 85 ed 49 8b 28 41 8b 48 0c 74 20 48 89 ef
[1034382.772572] RIP  [<ffffffffa02a1ec8>] con_work+0x14da/0x1d21 [libceph]
[1034382.772572]  RSP <ffff88007c15bdb0>
[1034382.772572] CR2: 0000000000000048
[1034382.772572] ---[ end trace 3a0fd4b4c9915722 ]---
[1034382.780594] BUG: unable to handle kernel paging request at fffffffffffffff8
[1034382.780603] IP: [<ffffffff8105f16a>] kthread_data+0x7/0xc
[1034382.780610] PGD 1607067 PUD 1608067 PMD 0
[1034382.780616] Oops: 0000 [#2] SMP
[1034382.780621] CPU 0
[1034382.780623] Modules linked in: rmd160 sha1_ssse3 sha1_generic hmac crypto_null camellia lzo cast6 cast5 deflate zlib_deflate cts ctr gcm ccm serpent blowfish_gen
eric blowfish_x86_64 blowfish_common twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common ecb xcbc sha256_generic sha512_generic des_generic xfrm_user ah
6 ah4 esp6 esp4 xfrm4_mode_beet xfrm4_tunnel tunnel4 xfrm4_mode_tunnel xfrm4_mode_transport xfrm6_mode_transport xfrm6_mode_ro xfrm6_mode_beet xfrm6_mode_tunnel ipcom
p ipcomp6 xfrm_ipcomp xfrm6_tunnel tunnel6 rng_core af_key ip6table_filter ip6_tables iptable_filter ip_tables x_tables xfs cryptd aes_x86_64 aes_generic cbc rbd libc
eph crc32c libcrc32c loop ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi scsi_mod nfsd nfs lockd fscach
e auth_rpcgss nfs_acl sunrpc ext3 jbd fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext4 mbcache jbd2 crc16 xen_blkfront xen_netfront
[1034382.780744]
[1034382.780748] Pid: 26554, comm: kworker/0:0 Tainted: G      D      3.2.0-2-amd64 #1
[1034382.780754] RIP: e030:[<ffffffff8105f16a>]  [<ffffffff8105f16a>] kthread_data+0x7/0xc
[1034382.780761] RSP: e02b:ffff88007c15ba80  EFLAGS: 00010002
[1034382.780765] RAX: 0000000000000000 RBX: ffff88007ff9e540 RCX: 0000000000000000
[1034382.780771] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88007c836f60
[1034382.780777] RBP: 0000000000000000 R08: 0000000000000400 R09: 0720072007200720
[1034382.780782] R10: dead000000200200 R11: 0720072007200720 R12: ffff88007c15bb40
[1034382.780787] R13: ffff88007d367510 R14: 0000000000000000 R15: ffff88007c837258
[1034382.780795] FS:  00007fa421c4b7a0(0000) GS:ffff88007ff8b000(0000) knlGS:0000000000000000
[1034382.780800] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[1034382.780805] CR2: fffffffffffffff8 CR3: 000000000306a000 CR4: 0000000000002660
[1034382.780811] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[1034382.780817] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[1034382.780822] Process kworker/0:0 (pid: 26554, threadinfo ffff88007c15a000, task ffff88007c836f60)
[1034382.780827] Stack:
[1034382.780830]  ffffffff8105c141 ffff88007ff9e540 ffff88007c836f60 ffff88007c15bb40
[1034382.780838]  ffffffff8133ff50 0000000000000200 ffff88007ff88b18 0000000000013540
[1034382.780847]  ffff88007c15bfd8 ffff88007c15bfd8 ffff88007c836f60 ffffffff8109457f
[1034382.780855] Call Trace:
[1034382.780860]  [<ffffffff8105c141>] ? wq_worker_sleeping+0xb/0x6f
[1034382.784413]  [<ffffffff8133ff50>] ? __schedule+0x138/0x5c3
[1034382.784413]  [<ffffffff8109457f>] ? arch_local_irq_restore+0x7/0x8
[1034382.784413]  [<ffffffff81048850>] ? release_task+0x31b/0x331
[1034382.784413]  [<ffffffff8103642f>] ? should_resched+0x5/0x23
[1034382.784413]  [<ffffffff81049fa2>] ? do_exit+0x730/0x732
[1034382.784413]  [<ffffffff81070747>] ? arch_local_irq_restore+0x7/0x8
[1034382.784413]  [<ffffffff8134254e>] ? oops_end+0xb1/0xb6
[1034382.784413]  [<ffffffff8133a958>] ? no_context+0x1ff/0x20e
[1034382.784413]  [<ffffffff81040e60>] ? find_busiest_group+0x1f5/0x805
[1034382.784413]  [<ffffffff81344559>] ? do_page_fault+0x1a8/0x337
[1034382.784413]  [<ffffffff8127602a>] ? sock_no_sendpage+0x88/0x95
[1034382.784413]  [<ffffffff812b62fb>] ? tcp_sendpage+0x47/0x418
[1034382.784413]  [<ffffffff81341cb5>] ? page_fault+0x25/0x30
[1034382.784413]  [<ffffffffa02a1ec8>] ? con_work+0x14da/0x1d21 [libceph]
[1034382.784413]  [<ffffffff81003129>] ? xen_end_context_switch+0xe/0x1c
[1034382.784413]  [<ffffffff81006c3f>] ? xen_restore_fl_direct_reloc+0x4/0x4
[1034382.784413]  [<ffffffffa02a09ee>] ? read_partial_message_section.isra.17+0x74/0x74 [libceph]
[1034382.784413]  [<ffffffff8105ae4d>] ? process_one_work+0x163/0x284
[1034382.784413]  [<ffffffff8105be15>] ? worker_thread+0xc2/0x145
[1034382.784413]  [<ffffffff8105bd53>] ? manage_workers.isra.23+0x15b/0x15b
[1034382.784413]  [<ffffffff8105ef51>] ? kthread+0x76/0x7e
[1034382.784413]  [<ffffffff81348834>] ? kernel_thread_helper+0x4/0x10
[1034382.784413]  [<ffffffff813468f3>] ? int_ret_from_sys_call+0x7/0x1b
[1034382.784413]  [<ffffffff81341a3c>] ? retint_restore_args+0x5/0x6
[1034382.784413]  [<ffffffff81348830>] ? gs_change+0x13/0x13
[1034382.784413] Code: 3f 48 c1 e5 03 48 c1 e0 06 48 8d b0 80 5f 40 81 48 29 ee e8 ec 35 fe ff 81 4b 14 00 00 00 04 41 59 5b 5d c3 48 8b 87 a0 02 00 00 <48> 8b 40 f8 c3 48 3b 3d 72 8f 72 00 75 08 0f bf 87 6a 06 00 00
[1034382.784413] RIP  [<ffffffff8105f16a>] kthread_data+0x7/0xc
[1034382.784413]  RSP <ffff88007c15ba80>
[1034382.784413] CR2: fffffffffffffff8
[1034382.784413] ---[ end trace 3a0fd4b4c9915723 ]---
[1034382.784413] Fixing recursive fault but reboot is needed!

a.patch View (423 Bytes) Karol Jurak, 05/29/2012 04:02 AM

kern.log-1.bz2 (2.14 MB) Karol Jurak, 06/01/2012 04:21 AM

kern.log-2.bz2 (3.01 MB) Karol Jurak, 06/01/2012 04:21 AM

History

#1 Updated by Alex Elder almost 12 years ago

  • Assignee set to Alex Elder

This could be in the same family as other problems in con_work() we've
seen lately (for example, 2260). Hoping a single root cause solves them
all; maybe I'm overly optimistic...

#2 Updated by Alex Elder almost 12 years ago

Reportedly, with the ceph configuration defined herein, the problem
shows up after simply restarting one of the osd processes (any one
of them).

However, he has a staging configuration and a production configuration,
and the problem only happens on the production one. The key difference
between the two is that the staging configuration has only one monitor
while the production configuration has three.

#3 Updated by Alex Elder almost 12 years ago

Staging cluster:
- running 0.45 on node n2cc: mds.n2cc, osd.1
- running 0.44 on node cc: mon.cc, mds.cc, osd.0

Production cluster:
- running 0.44 on node n3c1: mon.n3c1, mds.n3c1, osd.1
- running 0.44 on node n4c1: mon.n4c1, mds.n4c1, osd.0
- running 0.44 on node n8c1: mon.n8c1

The bug never showed up on the staging system even when
it was (all) running 0.44.

#4 Updated by Alex Elder almost 12 years ago

One more update. Maciej reports that after restoring the server again,
and restarting things (this again on the production machine), the client
crashed again shortly thereafter. This time there was no involvement
of any osd--that is, he did not shut down either of the osd's (nor did
either crash).

#5 Updated by Karol Jurak almost 12 years ago

I fairly often see almost identical crashes. They're triggered by simply restarting an OSD.

Ceph version: 0.46
Kernel client version: Debian's linux-image-3.3.0-trunk-amd64=3.3.4-1~experimental.1 patched so that the ceph client is 29275a2c2ac9dc5a8b9095304c649871baf43f4f (tip of the wip-crush branch at the time I built the kernel)

[1195106.458389] libceph: osd20 10.1.16.69:6800 socket closed
[1195106.500636] BUG: unable to handle kernel NULL pointer dereference at 0000000000000048
[1195106.500659] IP: [<ffffffffa0257d73>] con_work+0x1434/0x1c43 [libceph]
[1195106.500676] PGD 0 
[1195106.500682] Oops: 0000 [#1] SMP 
[1195106.500691] CPU 0 
[1195106.500694] Modules linked in: ext4 jbd2 crc16 rbd libceph ip6table_filter ip6_tables xt_tcpudp iptable_filter ip_tables loop autofs4 ipt_ULOG x_tables nfsd nfs lockd fscache auth_rpcgss nfs_acl sunrpc fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext3 jbd mbcache btrfs zlib_deflate crc32c libcrc32c xen_netfront xen_blkfront
[1195106.500772] 
[1195106.500777] Pid: 31011, comm: kworker/0:2 Not tainted 3.3.0-trunk-amd64 #1  
[1195106.500787] RIP: e030:[<ffffffffa0257d73>]  [<ffffffffa0257d73>] con_work+0x1434/0x1c43 [libceph]
[1195106.500801] RSP: e02b:ffff880001c3dd80  EFLAGS: 00010256
[1195106.500807] RAX: 0000000000000000 RBX: ffff880010fe5830 RCX: 0000000000000001
[1195106.500814] RDX: 0000000000000000 RSI: 0000000000073000 RDI: ffff88003d4f9218
[1195106.500822] RBP: ffff88003d4f9180 R08: 0000000000000003 R09: 00000000000005b4
[1195106.500829] R10: 000000000000001f R11: 000000000000001f R12: ffffea000095f7b8
[1195106.500836] R13: ffff880010fe5b08 R14: 0000000000000000 R15: ffff880010fe5858
[1195106.500847] FS:  00007fd9c73fd700(0000) GS:ffff88004a78b000(0000) knlGS:0000000000000000
[1195106.500856] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[1195106.500862] CR2: 0000000000000048 CR3: 000000004589c000 CR4: 0000000000000660
[1195106.500870] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[1195106.500877] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[1195106.500885] Process kworker/0:2 (pid: 31011, threadinfo ffff880001c3c000, task ffff8800487a6ea0)
[1195106.500893] Stack:
[1195106.500897]  ffffffff81003ef3 ffffffff81004091 ffffffff00000000 ffff880000001000
[1195106.500910]  ffffffffa8f7488f ffff880001c3de00 ffff880010fe5c20 0000000000080000
[1195106.500924]  0008000000000000 ffff880010fe5b01 ffff880010fe59a8 ffff880010fe5870
[1195106.500937] Call Trace:
[1195106.500946]  [<ffffffff81003ef3>] ? arch_local_irq_restore+0x7/0x8
[1195106.500954]  [<ffffffff81004091>] ? xen_mc_flush+0x124/0x153
[1195106.500965]  [<ffffffffa025693f>] ? read_partial_message_section.isra.17+0x7c/0x7c [libceph]
[1195106.500977]  [<ffffffff8104d5f7>] ? process_one_work+0x163/0x284
[1195106.500986]  [<ffffffff8104e047>] ? worker_thread+0xc2/0x145
[1195106.500994]  [<ffffffff8104df85>] ? manage_workers.isra.23+0x15b/0x15b
[1195106.501003]  [<ffffffff810512c2>] ? kthread+0x7d/0x85
[1195106.501013]  [<ffffffff81358a64>] ? kernel_thread_helper+0x4/0x10
[1195106.501023]  [<ffffffff8135287c>] ? retint_restore_args+0x5/0x6
[1195106.501031]  [<ffffffff81358a60>] ? gs_change+0x13/0x13
[1195106.501036] Code: 70 48 85 c0 74 09 4c 8b 20 49 83 ec 20 eb 32 48 83 bd 90 00 00 00 00 74 21 48 63 85 a0 00 00 00 48 8b 95 98 00 00 00 48 c1 e0 04 <48> 03 42 48 4c 8b 20 8b 48 0c 8b 50 08 eb 0e 4c 8b 25 3f fe 00 
[1195106.501138] RIP  [<ffffffffa0257d73>] con_work+0x1434/0x1c43 [libceph]
[1195106.501151]  RSP <ffff880001c3dd80>
[1195106.501156] CR2: 0000000000000048
[1195106.501163] ---[ end trace c05ce672ceb9aca2 ]---
[1195106.501253] BUG: unable to handle kernel paging request at fffffffffffffff8
[1195106.501263] IP: [<ffffffff810514e3>] kthread_data+0x7/0xc
[1195106.501272] PGD 1607067 PUD 1608067 PMD 0 
[1195106.501284] Oops: 0000 [#2] SMP 
[1195106.501291] CPU 0 
[1195106.501294] Modules linked in: ext4 jbd2 crc16 rbd libceph ip6table_filter ip6_tables xt_tcpudp iptable_filter ip_tables loop autofs4 ipt_ULOG x_tables nfsd nfs lockd fscache auth_rpcgss nfs_acl sunrpc fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext3 jbd mbcache btrfs zlib_deflate crc32c libcrc32c xen_netfront xen_blkfront
[1195106.501367] 
[1195106.501371] Pid: 31011, comm: kworker/0:2 Tainted: G      D      3.3.0-trunk-amd64 #1  
[1195106.501381] RIP: e030:[<ffffffff810514e3>]  [<ffffffff810514e3>] kthread_data+0x7/0xc
[1195106.501391] RSP: e02b:ffff880001c3da50  EFLAGS: 00010002
[1195106.501397] RAX: 0000000000000000 RBX: ffff88004a79e440 RCX: 0000000000000000
[1195106.501404] RDX: ffff8800484016e0 RSI: 0000000000000000 RDI: ffff8800487a6ea0
[1195106.501411] RBP: 0000000000000000 R08: 0000000000000400 R09: ffff88000b908680
[1195106.501418] R10: dead000000200200 R11: ffff88004a79e440 R12: ffff8800487a7198
[1195106.501426] R13: ffff880048767510 R14: 0000000000000000 R15: ffff8800487a70a0
[1195106.501435] FS:  00007fd9c73fd700(0000) GS:ffff88004a78b000(0000) knlGS:0000000000000000
[1195106.504276] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[1195106.504276] CR2: fffffffffffffff8 CR3: 000000004589c000 CR4: 0000000000000660
[1195106.504276] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[1195106.504276] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[1195106.504276] Process kworker/0:2 (pid: 31011, threadinfo ffff880001c3c000, task ffff8800487a6ea0)
[1195106.504276] Stack:
[1195106.504276]  ffffffff8104e3d7 ffff88004a79e440 ffff8800487a6ea0 ffff8800487a7198
[1195106.504276]  ffffffff813517ca 000000000184c35c ffff880045a86480 0000000000013440
[1195106.504276]  ffff880001c3dfd8 ffff880001c3dfd8 ffff8800487a6ea0 ffffffff8105711b
[1195106.504276] Call Trace:
[1195106.504276]  [<ffffffff8104e3d7>] ? wq_worker_sleeping+0xb/0x6f
[1195106.504276]  [<ffffffff813517ca>] ? __schedule+0x138/0x4e1
[1195106.504276]  [<ffffffff8105711b>] ? should_resched+0x5/0x23
[1195106.504276]  [<ffffffff8103bf2a>] ? do_exit+0x759/0x75b
[1195106.504276]  [<ffffffff81077dbb>] ? arch_local_irq_disable+0x7/0x8
[1195106.504276]  [<ffffffff81077db3>] ? arch_local_irq_restore+0x7/0x8
[1195106.504276]  [<ffffffff813534e4>] ? oops_end+0xb2/0xb7
[1195106.504276]  [<ffffffff8134c9dc>] ? no_context+0x256/0x265
[1195106.504276]  [<ffffffff81355541>] ? do_page_fault+0x1a8/0x337
[1195106.504276]  [<ffffffff813526bd>] ? _raw_spin_lock_bh+0xe/0x1c
[1195106.504276]  [<ffffffff812850a4>] ? release_sock+0x17/0x102
[1195106.504276]  [<ffffffff8103d1c6>] ? arch_local_save_flags+0x7/0x8
[1195106.504276]  [<ffffffff8103dcf3>] ? _local_bh_enable_ip.isra.11+0x1e/0x88
[1195106.504276]  [<ffffffff812c5f9f>] ? tcp_sendpage+0x405/0x417
[1195106.504276]  [<ffffffff81352af5>] ? page_fault+0x25/0x30
[1195106.504276]  [<ffffffffa0257d73>] ? con_work+0x1434/0x1c43 [libceph]
[1195106.504276]  [<ffffffff81003ef3>] ? arch_local_irq_restore+0x7/0x8
[1195106.504276]  [<ffffffff81004091>] ? xen_mc_flush+0x124/0x153
[1195106.504276]  [<ffffffffa025693f>] ? read_partial_message_section.isra.17+0x7c/0x7c [libceph]
[1195106.504276]  [<ffffffff8104d5f7>] ? process_one_work+0x163/0x284
[1195106.504276]  [<ffffffff8104e047>] ? worker_thread+0xc2/0x145
[1195106.504276]  [<ffffffff8104df85>] ? manage_workers.isra.23+0x15b/0x15b
[1195106.504276]  [<ffffffff810512c2>] ? kthread+0x7d/0x85
[1195106.504276]  [<ffffffff81358a64>] ? kernel_thread_helper+0x4/0x10
[1195106.504276]  [<ffffffff8135287c>] ? retint_restore_args+0x5/0x6
[1195106.504276]  [<ffffffff81358a60>] ? gs_change+0x13/0x13
[1195106.504276] Code: 3f 48 c1 e5 03 48 c1 e0 06 48 8d b0 50 54 40 81 48 29 ee e8 58 c0 00 00 81 4b 14 00 00 00 04 41 59 5b 5d c3 48 8b 87 a0 02 00 00 <48> 8b 40 f8 c3 48 3b 3d 79 43 72 00 75 08 0f bf 87 6a 06 00 00 
[1195106.504276] RIP  [<ffffffff810514e3>] kthread_data+0x7/0xc
[1195106.504276]  RSP <ffff880001c3da50>
[1195106.504276] CR2: fffffffffffffff8
[1195106.504276] ---[ end trace c05ce672ceb9aca3 ]---
[1195106.504276] Fixing recursive fault but reboot is needed!

#6 Updated by Karol Jurak almost 12 years ago

The variable which holds the NULL pointer is msg->bio_iter in write_partial_msg_pages in net/ceph/messenger.c. I confirmed that with the attached patch applied on top of d67556c5471206e44cab759c590667c0940c46ec (current tip of master).

[  420.215902] libceph: osd20 10.1.16.69:6800 socket closed
[  420.282176] ------------[ cut here ]------------
[  420.282196] kernel BUG at /var/home/karol/src/linux-2.6/master_bug-2267/linux-2.6-3.3.6/debian/build/source_amd64_none/net/ceph/messenger.c:880!
[  420.282206] invalid opcode: 0000 [#1] SMP 
[  420.282212] CPU 0 
[  420.282215] Modules linked in: ext4 jbd2 crc16 rbd libceph ip6table_filter ip6_tables ebtable_nat xt_tcpudp ebtables iptable_filter ip_tables autofs4 ipt_ULOG x_tables ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi scsi_mod nfs lockd fscache auth_rpcgss nfs_acl sunrpc fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext3 jbd mbcache dm_mod btrfs zlib_deflate crc32c libcrc32c xen_blkfront xen_netfront
[  420.282283] 
[  420.282289] Pid: 11950, comm: kworker/0:2 Not tainted 3.3.0-trunk-amd64 #1  
[  420.282297] RIP: e030:[<ffffffffa02cdd4b>]  [<ffffffffa02cdd4b>] con_work+0x1446/0x1c55 [libceph]
[  420.282316] RSP: e02b:ffff880046223d80  EFLAGS: 00010246
[  420.282321] RAX: 0000000000000000 RBX: ffff8800284d9030 RCX: 0000000000000009
[  420.282327] RDX: 0000000000000000 RSI: 0000000000075000 RDI: ffff8800456fbe58
[  420.282332] RBP: ffff8800456fbdc0 R08: 000000000000000f R09: 00000000601f480b
[  420.282337] R10: ffff880045696700 R11: ffff880045696700 R12: ffffea0000664390
[  420.282342] R13: 0000000000000000 R14: ffff8800284d9308 R15: ffff8800284d9420
[  420.282356] FS:  00007f0c714c0700(0000) GS:ffff880049800000(0000) knlGS:0000000000000000
[  420.282362] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[  420.282367] CR2: ffffffffff600400 CR3: 0000000044d00000 CR4: 0000000000000660
[  420.282375] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  420.282380] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  420.282386] Process kworker/0:2 (pid: 11950, threadinfo ffff880046222000, task ffff880045879020)
[  420.282392] Stack:
[  420.282395]  ffffffff81003ef3 ffffffff81004091 ffffffff00000000 ffff880000001000
[  420.282405]  ffffffff3cbe2a1c ffff880046223e00 ffff8800284d9058 000000000007c000
[  420.282413]  000000000007c000 ffff8800284d9070 ffff8800284d9301 ffff8800284d91a8
[  420.282422] Call Trace:
[  420.282432]  [<ffffffff81003ef3>] ? arch_local_irq_restore+0x7/0x8
[  420.282438]  [<ffffffff81004091>] ? xen_mc_flush+0x124/0x153
[  420.282447]  [<ffffffffa02cc905>] ? read_partial_message_section.isra.17+0x7c/0x7c [libceph]
[  420.282457]  [<ffffffff8104d5db>] ? process_one_work+0x163/0x284
[  420.282464]  [<ffffffff8104e02b>] ? worker_thread+0xc2/0x145
[  420.282470]  [<ffffffff8104df69>] ? manage_workers.isra.23+0x15b/0x15b
[  420.282477]  [<ffffffff810512a6>] ? kthread+0x7d/0x85
[  420.282487]  [<ffffffff81358c24>] ? kernel_thread_helper+0x4/0x10
[  420.282495]  [<ffffffff81352a3c>] ? retint_restore_args+0x5/0x6
[  420.282502]  [<ffffffff81358c20>] ? gs_change+0x13/0x13
[  420.282506] Code: d0 eb 4b 48 8b 45 70 48 85 c0 74 09 4c 8b 20 49 83 ec 20 eb 39 48 83 bd 90 00 00 00 00 74 28 48 8b 95 98 00 00 00 48 85 d2 75 02 <0f> 0b 48 63 85 a0 00 00 00 48 c1 e0 04 48 03 42 48 4c 8b 20 8b 
[  420.282559] RIP  [<ffffffffa02cdd4b>] con_work+0x1446/0x1c55 [libceph]
[  420.282568]  RSP <ffff880046223d80>
[  420.282583] ---[ end trace acd142ac7f33103c ]---
[  420.282666] BUG: unable to handle kernel paging request at fffffffffffffff8
[  420.282675] IP: [<ffffffff810514c7>] kthread_data+0x7/0xc
[  420.282688] PGD 1607067 PUD 1608067 PMD 0 
[  420.282695] Oops: 0000 [#2] SMP 
[  420.282699] CPU 0 
[  420.282701] Modules linked in: ext4 jbd2 crc16 rbd libceph ip6table_filter ip6_tables ebtable_nat xt_tcpudp ebtables iptable_filter ip_tables autofs4 ipt_ULOG x_tables ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi scsi_mod nfs lockd fscache auth_rpcgss nfs_acl sunrpc fuse evdev snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr ext3 jbd mbcache dm_mod btrfs zlib_deflate crc32c libcrc32c xen_blkfront xen_netfront
[  420.282759] 
[  420.282762] Pid: 11950, comm: kworker/0:2 Tainted: G      D      3.3.0-trunk-amd64 #1  
[  420.282770] RIP: e030:[<ffffffff810514c7>]  [<ffffffff810514c7>] kthread_data+0x7/0xc
[  420.282778] RSP: e02b:ffff880046223b00  EFLAGS: 00010002
[  420.282783] RAX: 0000000000000000 RBX: ffff880049813440 RCX: 0000000000000000
[  420.282788] RDX: ffff8800478016e0 RSI: 0000000000000000 RDI: ffff880045879020
[  420.282794] RBP: 0000000000000000 R08: 0000000000000400 R09: ffff88002ca9a3c0
[  420.282799] R10: dead000000200200 R11: ffff880049813440 R12: ffff880045879318
[  420.282805] R13: ffff880047b67510 R14: 0000000000000000 R15: ffff880045879220
[  420.282812] FS:  00007f0c714c0700(0000) GS:ffff880049800000(0000) knlGS:0000000000000000
[  420.282820] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[  420.282825] CR2: fffffffffffffff8 CR3: 0000000044d00000 CR4: 0000000000000660
[  420.282831] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  420.282837] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  420.282842] Process kworker/0:2 (pid: 11950, threadinfo ffff880046222000, task ffff880045879020)
[  420.282849] Stack:
[  420.282851]  ffffffff8104e3bb ffff880049813440 ffff880045879020 ffff880045879318
[  420.282860]  ffffffff81351992 ffff880049bbd688 ffff880045879020 0000000000013440
[  420.282869]  ffff880046223fd8 ffff880046223fd8 ffff880045879020 ffffffff810570ff
[  420.282877] Call Trace:
[  420.282882]  [<ffffffff8104e3bb>] ? wq_worker_sleeping+0xb/0x6f
[  420.282888]  [<ffffffff81351992>] ? __schedule+0x138/0x4e1
[  420.282896]  [<ffffffff810570ff>] ? should_resched+0x5/0x23
[  420.282903]  [<ffffffff8103bef4>] ? do_exit+0x723/0x725
[  420.282911]  [<ffffffff81077dcb>] ? arch_local_irq_disable+0x7/0x8
[  420.282917]  [<ffffffff81077dc3>] ? arch_local_irq_restore+0x7/0x8
[  420.282924]  [<ffffffff813536a4>] ? oops_end+0xb2/0xb7
[  420.282937]  [<ffffffff8100eadd>] ? do_invalid_op+0x87/0x91
[  420.282944]  [<ffffffffa02cdd4b>] ? con_work+0x1446/0x1c55 [libceph]
[  420.282951]  [<ffffffff8103d192>] ? arch_local_save_flags+0x7/0x8
[  420.282958]  [<ffffffff8103dcbf>] ? _local_bh_enable_ip.isra.11+0x1e/0x88
[  420.282967]  [<ffffffff812c617b>] ? tcp_sendpage+0x405/0x417
[  420.282973]  [<ffffffff81358a9b>] ? invalid_op+0x1b/0x20
[  420.282980]  [<ffffffffa02cdd4b>] ? con_work+0x1446/0x1c55 [libceph]
[  420.282986]  [<ffffffff81003ef3>] ? arch_local_irq_restore+0x7/0x8
[  420.282992]  [<ffffffff81004091>] ? xen_mc_flush+0x124/0x153
[  420.283000]  [<ffffffffa02cc905>] ? read_partial_message_section.isra.17+0x7c/0x7c [libceph]
[  420.283007]  [<ffffffff8104d5db>] ? process_one_work+0x163/0x284
[  420.283014]  [<ffffffff8104e02b>] ? worker_thread+0xc2/0x145
[  420.283020]  [<ffffffff8104df69>] ? manage_workers.isra.23+0x15b/0x15b
[  420.283026]  [<ffffffff810512a6>] ? kthread+0x7d/0x85
[  420.283032]  [<ffffffff81358c24>] ? kernel_thread_helper+0x4/0x10
[  420.283038]  [<ffffffff81352a3c>] ? retint_restore_args+0x5/0x6
[  420.283044]  [<ffffffff81358c20>] ? gs_change+0x13/0x13
[  420.283048] Code: 3f 48 c1 e5 03 48 c1 e0 06 48 8d b0 50 54 40 81 48 29 ee e8 62 c0 00 00 81 4b 14 00 00 00 04 41 59 5b 5d c3 48 8b 87 a0 02 00 00 <48> 8b 40 f8 c3 48 3b 3d 95 43 72 00 75 08 0f bf 87 6a 06 00 00 
[  420.283102] RIP  [<ffffffff810514c7>] kthread_data+0x7/0xc
[  420.283108]  RSP <ffff880046223b00>
[  420.283111] CR2: fffffffffffffff8
[  420.283115] ---[ end trace acd142ac7f33103d ]---
[  420.283120] Fixing recursive fault but reboot is needed!

#7 Updated by Alex Elder almost 12 years ago

  • Status changed from New to In Progress

The variable which holds the NULL pointer is msg->bio_iter in]
write_partial_msg_pages in net/ceph/messenger.c

That is an excellent finding! Sadly it doesn't lead me directly to
any sort of solution, but this narrows things down considerably.

It looks to me that in order for msg->bio_iter to be null, the
value of msg->bio itself must also be null. Are you able to
verify this? In fact, rather than simply calling BUG_ON() at
that spot, perhaps you could insert something like what's in
the following patch; we can get get a little more information
that might be helpful.

Index: b/net/ceph/messenger.c ===================================================================
--- a/net/ceph/messenger.c
+++ b/net/ceph/messenger.c
@ -970,6 +970,16 @ static int write_partial_msg_pages(struc
} else if (msg->bio) {
struct bio_vec *bv;

+ printk("%s:\n", func);
+ printk(" con->out_msg = %p\n", con->out_msg);
+ printk(" data_len = %u\n", data_len);
+ printk(" data_pos = %d\n",
+ con->out_msg_pos.data_pos);
+ printk(" trail_len = %zd\n", trail_len);
+ printk(" msg->bio_iter = %p\n", msg->bio_iter);
+ printk(" msg->bio_seg = %d\n", msg->bio_seg);
+ BUG_ON(msg->bio_iter == NULL);
+
bv = bio_iovec_idx(msg->bio_iter, msg->bio_seg);
page = bv->bv_page;
bio_offset = bv->bv_offset;

#8 Updated by Karol Jurak almost 12 years ago

Alex Elder wrote:

It looks to me that in order for msg->bio_iter to be null, the
value of msg->bio itself must also be null. Are you able to
verify this?

This can't be the case because there is a "} else if (msg->bio) {" condition.

In fact, rather than simply calling BUG_ON() at
that spot, perhaps you could insert something like what's in
the following patch; we can get get a little more information
that might be helpful.

Index: b/net/ceph/messenger.c ===================================================================
--- a/net/ceph/messenger.c
+++ b/net/ceph/messenger.c
@ -970,6 +970,16 @ static int write_partial_msg_pages(struc
} else if (msg->bio) {
struct bio_vec *bv;

+ printk("%s:\n", func);
+ printk(" con->out_msg = %p\n", con->out_msg);
+ printk(" data_len = %u\n", data_len);
+ printk(" data_pos = %d\n",
+ con->out_msg_pos.data_pos);
+ printk(" trail_len = %zd\n", trail_len);
+ printk(" msg->bio_iter = %p\n", msg->bio_iter);
+ printk(" msg->bio_seg = %d\n", msg->bio_seg);
+ BUG_ON(msg->bio_iter == NULL);
+
bv = bio_iovec_idx(msg->bio_iter, msg->bio_seg);
page = bv->bv_page;
bio_offset = bv->bv_offset;

I reproduced the crash with this patch applied. Console outputs from two clients are attached.

#9 Updated by Alex Elder over 11 years ago

  • Status changed from In Progress to Closed

A recent fix supplied by Zheng Yan of Intel seems to have fixed
this problem, so I'm closing this bug.

rbd: Clear ceph_msg->bio_iter for retransmitted message
commit 43643528
The bug can cause NULL pointer dereference in write_partial_msg_pages
Signed-off-by: Zheng Yan &lt;&gt;
Reviewed-by: Alex Elder &lt;&gt;

#10 Updated by Maciej Galkiewicz over 11 years ago

To which version do you plan to add this patch?

Also available in: Atom PDF