Re: The question about hfs+ patch (hfsplus: fix BUG on bnode parent update)

[Viacheslav Dubeyko <slava@dubeyko.com>]

On Mon, 2019-03-04 at 15:45 +0800, tchou wrote:
> tchou 於 2019-02-27 11:14 寫到:
> > 
> > Viacheslav Dubeyko 於 2019-02-27 10:56 寫到:
> > > 
> > > On Wed, 2019-02-27 at 09:46 +0800, tchou wrote:
> > > > 
> > > > Viacheslav Dubeyko 於 2019-02-27 02:01 寫到:
> > > > > 
> > > > > On Tue, 2019-02-26 at 11:32 +0800, tchou wrote:
> > > > > > 
> > > > > > Ernesto A. Fernández 於 2019-02-24 08:44 寫到:
> > > > > > > 
> > > > > > > 
> > > > > > > 
> > > > > [skipped]
> > > > > 
> > > > > > 
> > > > > > > 
> > > > > > > > 
> > > > > > > > 
> > > > > > > > [1]
> > > > > > > > =======================================================
> > > > > > > > ==========
> > > > > > > > =================================
> > > > > > > > 
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.504049]
> > > > > > > > hfsplus:
> > > > > > > > trying to free free bnode 294912(2)
> > > > > > > > 
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.510017]
> > > > > > > > hfsplus:
> > > > > > > > trying to free free bnode 294912(2)
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.515983]
> > > > > > > > hfsplus:
> > > > > > > > trying to free free bnode 294912(2)
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.521949]
> > > > > > > > general
> > > > > > > > protection fault: 0000 [#1] SMP
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.621069]
> > > > > > > > CPU: 1
> > > > > > > > PID:
> > > > > > > > 18715 Comm: SYNO.FileStatio Tainted: P C O 3.10.102
> > > > > > > > #15152
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.630308]
> > > > > > > > Hardware
> > > > > > > > name:
> > > > > > > > Synology Inc. DS1517+/Type2 - Board Product Name1, BIOS
> > > > > > > > M.405
> > > > > > > > 2017/05/09
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.640423]
> > > > > > > > task:
> > > > > > > > ffff8802753fa040 ti: ffff880270880000 task.ti:
> > > > > > > > ffff880270880000
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.648779]
> > > > > > > > RIP:
> > > > > > > > 0010:[<ffffffffa051459e>] [<ffffffffa051459e>]
> > > > > > > > hfsplus_bnode_write+0x9e/0x1e0 [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.659489]
> > > > > > > > RSP:
> > > > > > > > 0018:ffff880270883c18 EFLAGS: 00010202
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.665415]
> > > > > > > > RAX:
> > > > > > > > 0000000000000000 RBX: 0000000000000002 RCX:
> > > > > > > > 000000000000aeff
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.673391]
> > > > > > > > RDX:
> > > > > > > > 0000000000000000 RSI: ffff880270883c56 RDI:
> > > > > > > > db73880000000000
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.681366]
> > > > > > > > RBP:
> > > > > > > > ffff88005f7b1920 R08: 0000000000000002 R09:
> > > > > > > > 0000000000000002
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.689343]
> > > > > > > > R10:
> > > > > > > > ffff88005f7b18d0 R11: 0000000000000002 R12:
> > > > > > > > 0000000000001ffc
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.697310]
> > > > > > > > R13:
> > > > > > > > ffff880270883c56 R14: 0000000000000002 R15:
> > > > > > > > 0000000000000002
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.705286]
> > > > > > > > FS:
> > > > > > > > 00007f4fee0607c0(0000) GS:ffff88027fc40000(0000)
> > > > > > > > knlGS:0000000000000000
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.714322]
> > > > > > > > CS: 0010
> > > > > > > > DS:
> > > > > > > > 0000 ES: 0000 CR0: 000000008005003b
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.720744]
> > > > > > > > CR2:
> > > > > > > > 00007f4fee05d000 CR3: 0000000247210000 CR4:
> > > > > > > > 00000000001007e0
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.728711]
> > > > > > > > DR0:
> > > > > > > > 0000000000000000 DR1: 0000000000000000 DR2:
> > > > > > > > 0000000000000000
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.736687]
> > > > > > > > DR3:
> > > > > > > > 0000000000000000 DR6: 00000000ffff0ff0 DR7:
> > > > > > > > 0000000000000400
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.744654]
> > > > > > > > Stack:
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.746896]
> > > > > > > > ffff88005f7b18c0 ffff880270883cd0 0000000000001ffc
> > > > > > > > 0000000000001f9c
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.755181]
> > > > > > > > 0000000000000060 000000000000000e ffffffffa05146ff
> > > > > > > > aeff000000000031
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.763468]
> > > > > > > > ffffffffa0516bf9 000000606228c340 ffff880270883cd0
> > > > > > > > 00000000fffffffe
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.771763]
> > > > > > > > Call
> > > > > > > > Trace:
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.774497]
> > > > > > > > [<ffffffffa05146ff>] ?
> > > > > > > > hfsplus_bnode_write_u16+0x1f/0x30
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.782671]
> > > > > > > > [<ffffffffa0516bf9>] ? hfsplus_brec_remove+0x129/0x190
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.790650]
> > > > > > > > [<ffffffffa05191d0>] ? __hfsplus_delete_attr+0x90/0xf0
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.798629]
> > > > > > > > [<ffffffffa0519979>] ?
> > > > > > > > hfsplus_delete_all_attrs+0x49/0xb0
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.806900]
> > > > > > > > [<ffffffffa0512482>] ? hfsplus_delete_cat+0x1c2/0x2b0
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.814782]
> > > > > > > > [<ffffffffa0512d90>] ? hfsplus_unlink+0x1d0/0x1e0
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.822277]
> > > > > > > > [<ffffffff811066bd>] ? __inode_permission+0x1d/0xb0
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.828992]
> > > > > > > > [<ffffffff8110a72a>] ? vfs_unlink+0x8a/0x100
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.835025]
> > > > > > > > [<ffffffff8110a9c3>] ? do_unlinkat+0x223/0x230
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.841255]
> > > > > > > > [<ffffffff8111d853>] ? mntput_no_expire+0x13/0x130
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.847873]
> > > > > > > > [<ffffffff8104d1bc>] ? task_work_run+0x9c/0xe0
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.854102]
> > > > > > > > [<ffffffff81002901>] ? do_notify_resume+0x61/0x90
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.860624]
> > > > > > > > [<ffffffff810fb827>] ? fput+0x57/0xb0
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.865978]
> > > > > > > > [<ffffffff8149dd32>] ? system_call_fastpath+0x16/0x1b
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.872884]
> > > > > > > > Code: 48
> > > > > > > > 63 ca
> > > > > > > > 48 01 cf 48 83 fb 08 0f 83 fd 00 00 00 31 c0 41 f6 c3
> > > > > > > > 04 74 09 8b
> > > > > > > > 06
> > > > > > > > 89 07 b8 04 00 00 00 41 f6 c3 02 74 0c 0f b7 0c 06 <66>
> > > > > > > > 89 0c 07
> > > > > > > > 48 8d
> > > > > > > > 40 02 41 83 e3 01 74 07 0f b6 0c 06 88 0c 07
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.894293]
> > > > > > > > RIP
> > > > > > > > [<ffffffffa051459e>] hfsplus_bnode_write+0x9e/0x1e0
> > > > > > > > [hfsplus]
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.902375]
> > > > > > > > RSP
> > > > > > > > <ffff880270883c18>
> > > > > > > > 
> > > > > > > > 2017-08-30T10:32:30-04:00 BS-SAN kernel: [ 5471.906350]
> > > > > > > > ---[ end
> > > > > > > > trace
> > > > > > > > 0e65d1ee34a1e12e ]---
> > > > > > > > 
> > > > > > > > 
> > > > > > > > =======================================================
> > > > > > > > ==========
> > > > > > > > =================================
> > > > > > > > 
> > > > > 
> > > > > Could you please share more details about the environment of
> > > > > the bug?
> > > > > Do you know what operation trigger the bug? How had volume
> > > > > been
> > > > > created? Can you reproduce the issue?
> > > > > 
> > > > > It looks like the file deletion operation took place. Do you
> > > > > have any
> > > > > idea what file is under deletion and what features it has?
> > > > > Does this
> > > > > file contain any xattr?
> > > > Ok, the following description is my situation. The Linux
> > > > versions of
> > > > our products are 3.10 and 4.4.
> > > > 
> > > > Users may plug-in the external USB drive, whose hfs+ is
> > > > formatted on
> > > > their macOS device, to our device.  They can do all file system
> > > > operations(etc create, remove, rename files, and so on) on both
> > > > macOS side and Linux side.
> > > > 
> > > > The files created on macOS have the default xattr:
> > > > com.apple.FinderInfo=0sAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAK
> > > > rmU=
> > > > The files created on Linux have no xattr.
> > > > 
> > > > Some users seem enconter the call trace when removing the file
> > > > on
> > > > our device.And it will stock when we unmount it and cause the
> > > > unmount fail.
> > > > 
> > > > We cannot reproduce it by ourselves. The following link is the
> > > > only one I can find that have the same situation of mine:
> > > > https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1646565/co
> > > > mments/5
> > > > 
> > > > I try some reproduce ways:
> > > > 1. Format the USB drive on Linux and macOS.
> > > > 2. Use fsstress to stress create and unlink operations on
> > > > Linux.
> > > > 3. Create and remove the 100,000 files on Linux.
> > > > 4. Create 10,000 ~ 500,000 files on MacOS and remove all on
> > > > Linux.
> > > > All of ways failed.
> > > > 
> > > > There are about 10+ users enconter this situation so I try to
> > > > fix it.
> > > > Any Idea about it?
> > > OK. I see the point. Let's achieve the stable reproduction of
> > > the 
> > > issue
> > > at first. The issue is triggered by operations in the Attributes
> > > Tree
> > > but not in the Catalog Tree. So, it will be enough to create the 
> > > several
> > > files. The key trick is to create many xattrs for one file. It
> > > will be
> > > better to create xattrs by native way under Macx OS X. I believe
> > > that
> > > Attributes Tree's node size could be about 8 KB by default (but
> > > maybe 
> > > 4
> > > KB only). It is better to check the size in superblock's dump,
> > > for
> > > example. So, it needs to create a lot of xattrs for one file (or 
> > > several
> > > files) with the goal to create the Attributes Tree with enough
> > > number 
> > > of
> > > nodes. The best case will be to create the Attributes Tree with
> > > height
> > > of 2 or 3 with the goal to have the index nodes too. As far as I
> > > can
> > > judge, the issue can be reproduce during the deletion of the
> > > xattrs or
> > > file with xattrs under Linux. And it needs to have the Attributes
> > > Tree
> > > with many nodes because the issue should be triggered during the
> > > operation of the b-tree node deletion.
> > > 
> > > So, I hope my vision could help. Could you please try to
> > > reproduce the
> > > issue and to share the results?
> > Thanks for your advice! I will try to reproduce it. And we have a 
> > four-day
> > vacations in our country from tomorrow on. I will try it at 3/4 ~
> > 3/5.
> > Please forgive the delay.
> > 
> > 
> Sorry for delay, I finish the reproduce steps. And it works!
> I try it on our product with kernel 3.10 and ubuntu with kernel 4.19
> Both environmnets can reproduce the bug.
> 
> I use two ways to reproduce:
> =====================================================================
> =========
> 1). mkfs the hfs+ image on linux
> 1. touch file on it.
> 2. add enouth xattrs in the file
> for x in $(seq 1 1000)
>    do setfattr -n user.$x -v "gggg${x}gggg${x}qqqqq${x}pleaseggggg" 
> /mnt/1
> done
> 3. rm the file
> 4. segmentation fault and get the same call trace
> 5. the fsck.hfsplus result:
> ** img2 (NO WRITE)
> ** Checking HFS Plus volume.
> ** Checking Extents Overflow file.
> ** Checking Catalog file.
>     Invalid leaf record count
>     (It should be 4 instead of 6)
> ** Checking Catalog hierarchy.
>     Invalid directory item count
>     (It should be 1 instead of 2)
> ** Checking Extended Attributes file.
>     Invalid index key
> (8, 1)
> ** The volume untitled needs to be repaired.
> =====================================================================
> =========
> 2). format hfs+ on mac
> 1. touch file on it.
> 2.add enouth xattrs in the file
> for x in $(seq 1 1000)
>    do xattr -w user.$x "gggg${x}gggg${x}qqqqq${x}pleaseggggg" 
> /Volumes/test/1
> done
> 3. move the usb disk to linux
> 4. rm the file
> 5. segmentation fault and get the same call trace
> 6. the fsck.hfsplus result:
> ** /dev/sdq1 (NO WRITE)
> ** Checking HFS Plus volume.
> ** Checking Extents Overflow file.
> ** Checking Catalog file.
> ** Checking Catalog hierarchy.
> ** Checking Extended Attributes file.
> ** Checking volume bitmap.
> ** Checking volume information.
>     Volume Header needs minor repair
> (2, 0)
> ** The volume test needs to be repaired.
> =====================================================================
> =========
> 
> It seems that the guess it correct. The Attributes Tree with enough 
> number of
> node can trigger the bug.

Do you see the same call trace? Could you share the call trace in your
case? Could you identify the code line in the source code that trigger
the bug?

Thanks,
Vyacheslav Dubeyko.