raid5 regression in 4.1.x

raid5 regression in 4.1.x

[Tomas Papan]

[-- Attachment #1: Type: text/plain, Size: 328 bytes --]

Hello there,

I found a bug on my system. I do not know if this was already
reported. I can't find it anywhere.
Would you please have a look at this trace (attached)



Unfortunately it happens completely random (after few days in this
case, with 4.1.0 it was in matter of hours) and I'm not able to bisect
this.

Regards
Tomas

[-- Attachment #2: kernel-bug.txt --]
[-- Type: text/plain, Size: 5913 bytes --]

Jul 29 08:47:53 anakin kernel: BUG: unable to handle kernel NULL pointer dereference at           (null)
Jul 29 08:47:53 anakin kernel: IP: [<ffffffff812d2226>] get_free_stripe+0x1b/0x7e
Jul 29 08:47:53 anakin kernel: PGD 32faa7067 PUD 172863067 PMD 0 
Jul 29 08:47:53 anakin kernel: Oops: 0000 [#1] PREEMPT SMP 
Jul 29 08:47:53 anakin kernel: Modules linked in: veth xt_CHECKSUM iptable_mangle xt_addrtype dm_thin_pool dm_persistent_data libcrc32c dm_bio_prison dm_bufio ebtables algif_skcipher af_alg it87 hwmon_vid cls_route cls_u32 cls_fw sch_sfq sch_htb ctr ccm xt_REDIRECT nf_nat_redirect xt_nat ipt_MASQUERADE nf_nat_masquerade_ipv4 xt_limit ipt_REJECT nf_reject_ipv4 xt_tcpudp nf_conntrack_ipv6 nf_defrag_ipv6 xt_conntrack iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack ip6table_filter ip6_tables iptable_filter ip_tables x_tables sit tunnel4 ip_tunnel loop r8169 mii fuse iwldvm led_class mac80211 kvm_intel kvm i2c_i801 iwlwifi i2c_core alx cfg80211 mdio e1000e
Jul 29 08:47:53 anakin kernel: CPU: 0 PID: 15122 Comm: git Not tainted 4.1.3 #1
Jul 29 08:47:53 anakin kernel: Hardware name: Gigabyte Technology Co., Ltd. Z87N-WIFI/Z87N-WIFI, BIOS F3d 06/19/2013
Jul 29 08:47:53 anakin kernel: task: ffff880426a19080 ti: ffff880047864000 task.ti: ffff880047864000
Jul 29 08:47:53 anakin kernel: RIP: 0010:[<ffffffff812d2226>]  [<ffffffff812d2226>] get_free_stripe+0x1b/0x7e
Jul 29 08:47:53 anakin kernel: RSP: 0018:ffff8800478676c0  EFLAGS: 00010013
Jul 29 08:47:53 anakin kernel: RAX: ffff88042b2d4d60 RBX: ffff88042b2d4c00 RCX: ffff88042b2d4d68
Jul 29 08:47:53 anakin kernel: RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff88042b2d4c00
Jul 29 08:47:53 anakin kernel: RBP: 00000000ffffffff R08: 0000000000000007 R09: ffff88042b2da000
Jul 29 08:47:53 anakin kernel: R10: ffff880434a2de00 R11: ffff880432f5cf80 R12: ffff88042b2d4c06
Jul 29 08:47:53 anakin kernel: R13: ffff88042b2d4e40 R14: 0000000000000000 R15: 0000000000000d66
Jul 29 08:47:53 anakin kernel: FS:  00007f054d7fa700(0000) GS:ffff88043f200000(0000) knlGS:0000000000000000
Jul 29 08:47:53 anakin kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 29 08:47:53 anakin kernel: CR2: 0000000000000000 CR3: 0000000378d50000 CR4: 00000000001427f0
Jul 29 08:47:53 anakin kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jul 29 08:47:53 anakin kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Jul 29 08:47:53 anakin kernel: Stack:
Jul 29 08:47:53 anakin kernel:  ffffffff812d5ac1 0000000000000073 ffff88042b2d4c00 ffff880047867738
Jul 29 08:47:53 anakin kernel:  ffffffff812d5b2b 0000000000000df3 0000000000000080 0000000000000000
Jul 29 08:47:53 anakin kernel:  ffffffff810d55f6 0000000000001fb8 0000000000000e80 0000000000000080
Jul 29 08:47:53 anakin kernel: Call Trace:
Jul 29 08:47:53 anakin kernel:  [<ffffffff812d5ac1>] ? drop_one_stripe+0x30/0x78
Jul 29 08:47:53 anakin kernel:  [<ffffffff812d5b2b>] ? raid5_cache_scan+0x22/0x33
Jul 29 08:47:53 anakin kernel:  [<ffffffff810d55f6>] ? shrink_slab+0x1b8/0x22e
Jul 29 08:47:53 anakin kernel:  [<ffffffff810d7d3d>] ? shrink_zone+0x160/0x24c
Jul 29 08:47:53 anakin kernel:  [<ffffffff810d7fc2>] ? do_try_to_free_pages+0x199/0x32e
Jul 29 08:47:53 anakin kernel:  [<ffffffff810d81e5>] ? try_to_free_pages+0x8e/0x94
Jul 29 08:47:53 anakin kernel:  [<ffffffff810d0523>] ? __alloc_pages_nodemask+0x53c/0x79f
Jul 29 08:47:53 anakin kernel:  [<ffffffff810faf62>] ? new_slab+0xa2/0x338
Jul 29 08:47:53 anakin kernel:  [<ffffffff813dc214>] ? __slab_alloc.isra.67.constprop.69+0x20a/0x304
Jul 29 08:47:53 anakin kernel:  [<ffffffff811705d0>] ? ext4_alloc_inode+0x12/0x176
Jul 29 08:47:53 anakin kernel:  [<ffffffff811634db>] ? ext4_map_blocks+0x1d2/0x3b4
Jul 29 08:47:53 anakin kernel:  [<ffffffff81192f18>] ? ext4_fname_crypto_free_buffer+0x11/0x1a
Jul 29 08:47:53 anakin kernel:  [<ffffffff811705d0>] ? ext4_alloc_inode+0x12/0x176
Jul 29 08:47:53 anakin kernel:  [<ffffffff810fc049>] ? kmem_cache_alloc+0x7a/0x12a
Jul 29 08:47:53 anakin kernel:  [<ffffffff811705d0>] ? ext4_alloc_inode+0x12/0x176
Jul 29 08:47:53 anakin kernel:  [<ffffffff8111e01b>] ? alloc_inode+0x14/0x6e
Jul 29 08:47:53 anakin kernel:  [<ffffffff8111ed9f>] ? iget_locked+0x5f/0x13a
Jul 29 08:47:53 anakin kernel:  [<ffffffff81163b66>] ? ext4_iget+0x27/0x8b9
Jul 29 08:47:53 anakin kernel:  [<ffffffff8111cc60>] ? __d_lookup+0x125/0x137
Jul 29 08:47:53 anakin kernel:  [<ffffffff8116bcf8>] ? ext4_lookup+0xe7/0x1ae
Jul 29 08:47:53 anakin kernel:  [<ffffffff81111bec>] ? lookup_real+0x23/0x3d
Jul 29 08:47:53 anakin kernel:  [<ffffffff811124bc>] ? __lookup_hash+0x2a/0x31
Jul 29 08:47:53 anakin kernel:  [<ffffffff81113ba1>] ? lookup_slow+0x39/0x9c
Jul 29 08:47:53 anakin kernel:  [<ffffffff811154f3>] ? path_lookupat+0xe1/0x665
Jul 29 08:47:53 anakin kernel:  [<ffffffff81115a92>] ? filename_lookup+0x1b/0x58
Jul 29 08:47:53 anakin kernel:  [<ffffffff81116d53>] ? user_path_at_empty+0x48/0x7d
Jul 29 08:47:53 anakin kernel:  [<ffffffff810e3102>] ? list_lru_add+0x66/0x86
Jul 29 08:47:53 anakin kernel:  [<ffffffff8110e57e>] ? cp_new_stat+0x111/0x124
Jul 29 08:47:53 anakin kernel:  [<ffffffff8110e3f7>] ? vfs_fstatat+0x3e/0x8d
Jul 29 08:47:53 anakin kernel:  [<ffffffff8110e7fd>] ? SyS_newlstat+0x12/0x2b
Jul 29 08:47:53 anakin kernel:  [<ffffffff813e1a17>] ? system_call_fastpath+0x12/0x6a
Jul 29 08:47:53 anakin kernel: Code: 74 0d ff ca 39 d7 0f 94 c0 0f b6 c0 c3 31 c0 c3 48 63 c6 48 83 c0 17 48 c1 e0 04 48 01 f8 48 8d 48 08 48 39 09 74 64 48 8b 50 08 <4c> 8b 0a 48 8d 42 f0 4c 8b 42 08 4d 89 41 08 4d 89 08 4c 8b 4a 
Jul 29 08:47:53 anakin kernel: RIP  [<ffffffff812d2226>] get_free_stripe+0x1b/0x7e
Jul 29 08:47:53 anakin kernel:  RSP <ffff8800478676c0>
Jul 29 08:47:53 anakin kernel: CR2: 0000000000000000
Jul 29 08:47:53 anakin kernel: ---[ end trace 8b8e4636b0689591 ]---

Re: raid5 regression in 4.1.x

[NeilBrown]

On Wed, 29 Jul 2015 09:21:22 +0200 Tomas Papan <tomas.papan@gmail.com>
wrote:

> Hello there,
> 
> I found a bug on my system. I do not know if this was already
> reported. I can't find it anywhere.
> Would you please have a look at this trace (attached)
> 
> 
> 
> Unfortunately it happens completely random (after few days in this
> case, with 4.1.0 it was in matter of hours) and I'm not able to bisect
> this.
> 
> Regards
> Tomas

Thanks for the report.

The crash is happening in get_free_stripe() and the 'hash' argument is
stored in register RSI and has (32bit) value 0xFFFFFFFF.  i.e. -1.
That shouldn't happen - it should be from 0 to 7.

get_free_stripe was called from drop_one_stripe():

	int hash = (conf->max_nr_stripes - 1) % NR_STRIPE_HASH_LOCKS;

	spin_lock_irq(conf->hash_locks + hash);
	sh = get_free_stripe(conf, hash);

so it seems that conf->max-nr_stripes was 0, which it really should
never be.

There is a patch submitted for 4.2 which should get into -stable a
couple of weeks later which might help.

If you would like to try just applying that patch and see if the
problem goes away, it is

http://git.neil.brown.name/?p=md.git;a=commitdiff;h=2d5b569b665ea6d0b15c52529ff06300de81a7ce

or

http://git.neil.brown.name/?p=md.git;a=commitdiff_plain;h=2d5b569b665ea6d0b15c52529ff06300de81a7ce

I'll have another look at the code a bit later and see if I can
convince myself what happened.

Thanks,
NeilBrown

Re: raid5 regression in 4.1.x

[Tomas Papan]

Hi Neil,

Thanks for the explanation, I've installed the 4.2.0-rc4 (which has
your patch in it).
It booted and so far dmesg looks clean. I'll report back in couple of days.

Thanks
Tomas

On Fri, Jul 31, 2015 at 12:57 AM, NeilBrown <neilb@suse.com> wrote:
> On Wed, 29 Jul 2015 09:21:22 +0200 Tomas Papan <tomas.papan@gmail.com>
> wrote:
>
>> Hello there,
>>
>> I found a bug on my system. I do not know if this was already
>> reported. I can't find it anywhere.
>> Would you please have a look at this trace (attached)
>>
>>
>>
>> Unfortunately it happens completely random (after few days in this
>> case, with 4.1.0 it was in matter of hours) and I'm not able to bisect
>> this.
>>
>> Regards
>> Tomas
>
> Thanks for the report.
>
> The crash is happening in get_free_stripe() and the 'hash' argument is
> stored in register RSI and has (32bit) value 0xFFFFFFFF.  i.e. -1.
> That shouldn't happen - it should be from 0 to 7.
>
> get_free_stripe was called from drop_one_stripe():
>
>         int hash = (conf->max_nr_stripes - 1) % NR_STRIPE_HASH_LOCKS;
>
>         spin_lock_irq(conf->hash_locks + hash);
>         sh = get_free_stripe(conf, hash);
>
> so it seems that conf->max-nr_stripes was 0, which it really should
> never be.
>
> There is a patch submitted for 4.2 which should get into -stable a
> couple of weeks later which might help.
>
> If you would like to try just applying that patch and see if the
> problem goes away, it is
>
> http://git.neil.brown.name/?p=md.git;a=commitdiff;h=2d5b569b665ea6d0b15c52529ff06300de81a7ce
>
> or
>
> http://git.neil.brown.name/?p=md.git;a=commitdiff_plain;h=2d5b569b665ea6d0b15c52529ff06300de81a7ce
>
> I'll have another look at the code a bit later and see if I can
> convince myself what happened.
>
> Thanks,
> NeilBrown