The issue still can be reproduced on the latest linux tree[2].
To reproduce I need to run about 1000 times blktests block/001, and
bisect shows it was introduced with commit[1], as it was not 100%
reproduced, not sure if it's the culprit?
[1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
[2]
[ 2304.536339] scsi 48:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.540805] sr 50:0:0:0: Attached scsi CD-ROM sr3
[ 2304.544574] scsi 48:0:0:0: Power-on or device reset occurred
[ 2304.600645] sr 48:0:0:0: [sr1] scsi-1 drive
[ 2304.616364] scsi 51:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.624639] scsi 51:0:0:0: Power-on or device reset occurred
[ 2304.626634] sr 48:0:0:0: Attached scsi CD-ROM sr1
[ 2304.680537] sr 51:0:0:0: [sr2] scsi-1 drive
[ 2304.706394] sr 51:0:0:0: Attached scsi CD-ROM sr2
[ 2304.746329] scsi 49:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.754569] scsi 49:0:0:0: Power-on or device reset occurred
[ 2304.756302] scsi 50:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.768483] scsi 50:0:0:0: Power-on or device reset occurred
[ 2304.806321] scsi 48:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.810587] sr 49:0:0:0: [sr0] scsi-1 drive
[ 2304.814561] scsi 48:0:0:0: Power-on or device reset occurred
[ 2304.824475] sr 50:0:0:0: [sr3] scsi-1 drive
[ 2304.836384] scsi 51:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2304.840364] sr 49:0:0:0: Attached scsi CD-ROM sr0
[ 2304.844619] scsi 51:0:0:0: Power-on or device reset occurred
[ 2304.850444] sr 50:0:0:0: Attached scsi CD-ROM sr3
[ 2304.874563] sr 48:0:0:0: [sr1] scsi-1 drive
[ 2304.900660] sr 51:0:0:0: [sr2] scsi-1 drive
[ 2304.901506] sr 48:0:0:0: Attached scsi CD-ROM sr1
[ 2304.926306] sr 51:0:0:0: Attached scsi CD-ROM sr2
[ 2305.056432] scsi 50:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2305.056572] scsi 49:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2305.064635] scsi 50:0:0:0: Power-on or device reset occurred
[ 2305.072821] scsi 49:0:0:0: Power-on or device reset occurred
[ 2305.086286] scsi 51:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2305.086357] scsi 48:0:0:0: CD-ROM Linux scsi_debug
0191 PQ: 0 ANSI: 7
[ 2305.094521] scsi 51:0:0:0: Power-on or device reset occurred
[ 2305.102693] scsi 48:0:0:0: Power-on or device reset occurred
[ 2305.128785] sr 50:0:0:0: [sr0] scsi-1 drive
[ 2305.134445] sr 49:0:0:0: [sr1] scsi-1 drive
[ 2305.154728] sr 50:0:0:0: Attached scsi CD-ROM sr0
[ 2305.158607] sr 51:0:0:0: [sr2] scsi-1 drive
[ 2305.160392] sr 49:0:0:0: Attached scsi CD-ROM sr1
[ 2305.164254] sr 48:0:0:0: [sr3] scsi-1 drive
[ 2305.184185] sr 51:0:0:0: Attached scsi CD-ROM sr2
[ 2305.190086] sr 48:0:0:0: Attached scsi CD-ROM sr3
[ 2305.555658] Unable to handle kernel execute from non-executable
memory at virtual address ffffc61b656052e8
[ 2305.565301] Mem abort info:
[ 2305.568086] ESR = 0x000000008600000e
[ 2305.571822] EC = 0x21: IABT (current EL), IL = 32 bits
[ 2305.577123] SET = 0, FnV = 0
[ 2305.580164] EA = 0, S1PTW = 0
[ 2305.583292] FSC = 0x0e: level 2 permission fault
[ 2305.588074] swapper pgtable: 4k pages, 48-bit VAs, pgdp=0000080731fa0000
[ 2305.594761] [ffffc61b656052e8] pgd=1000080ffffff003,
p4d=1000080ffffff003, pud=1000080fffffe003, pmd=0068080732e00f01
[ 2305.605362] Internal error: Oops: 000000008600000e [#1] SMP
[ 2305.610922] Modules linked in: scsi_debug sr_mod pktcdvd cdrom
rfkill sunrpc vfat fat acpi_ipmi arm_spe_pmu ipmi_ssif ipmi_devintf
ipmi_msghandler arm_cmn arm_dmc620_pmu arm_dsu_pmu cppc_cpufreq loop
fuse zram xfs crct10dif_ce ghash_ce nvme sha2_ce nvme_core
sha256_arm64 igb sha1_ce ast sbsa_gwdt nvme_common
i2c_designware_platform i2c_algo_bit i2c_designware_core xgene_hwmon
dm_mod [last unloaded: scsi_debug]
[ 2305.647236] CPU: 85 PID: 1 Comm: systemd Kdump: loaded Not tainted
6.6.0-rc1+ #13
[ 2305.654706] Hardware name: GIGABYTE R152-P31-00/MP32-AR1-00, BIOS
F31n (SCP: 2.10.20220810) 09/30/2022
[ 2305.663997] pstate: 20400009 (nzCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 2305.670946] pc : in_lookup_hashtable+0x1138/0x2000
[ 2305.675728] lr : rcu_do_batch+0x194/0x488
[ 2305.679727] sp : ffff8000802abe60
[ 2305.683029] x29: ffff8000802abe60 x28: ffffc61b6524c7c0 x27: ffffc61b63452f40
[ 2305.690152] x26: ffff080f37ab6438 x25: 000000000000000a x24: 0000000000000000
[ 2305.697274] x23: 0000000000000002 x22: ffff8000802abec0 x21: ffff080f37ab63c0
[ 2305.704396] x20: ffff07ff8136a580 x19: 0000000000000003 x18: 0000000000000000
[ 2305.711519] x17: ffff41f3d3161000 x16: ffff8000802a8000 x15: 0000000000000000
[ 2305.718641] x14: 0000000000000000 x13: ffff07ffa131802d x12: ffff80008041bb94
[ 2305.725764] x11: 0000000000000040 x10: ffff07ff802622e8 x9 : ffffc61b63452e30
[ 2305.732887] x8 : 000002189dce1780 x7 : ffff07ff8d5c1000 x6 : ffff41f3d3161000
[ 2305.740009] x5 : ffff07ff8136a580 x4 : ffff080f37aba960 x3 : 000000001550a055
[ 2305.747131] x2 : 0000000000000000 x1 : ffffc61b656052e8 x0 : ffff080184c565f0
[ 2305.754254] Call trace:
[ 2305.756687] in_lookup_hashtable+0x1138/0x2000
[ 2305.761119] rcu_core+0x268/0x350
[ 2305.764422] rcu_core_si+0x18/0x30
[ 2305.767812] __do_softirq+0x120/0x3d4
[ 2305.771462] ____do_softirq+0x18/0x30
[ 2305.775112] call_on_irq_stack+0x24/0x30
[ 2305.779022] do_softirq_own_stack+0x24/0x38
[ 2305.783192] __irq_exit_rcu+0xfc/0x130
[ 2305.786929] irq_exit_rcu+0x18/0x30
[ 2305.790404] el1_interrupt+0x4c/0xe8
[ 2305.793969] el1h_64_irq_handler+0x18/0x28
[ 2305.798052] el1h_64_irq+0x78/0x80
[ 2305.801441] d_same_name+0x50/0xd0
[ 2305.804832] __lookup_slow+0x64/0x158
[ 2305.808482] walk_component+0xe0/0x1a0
[ 2305.812219] path_lookupat+0x7c/0x1b8
[ 2305.815869] filename_lookup+0xb4/0x1b8
[ 2305.819692] vfs_statx+0x94/0x1a8
[ 2305.822995] vfs_fstatat+0xd4/0x110
[ 2305.826471] __do_sys_newfstatat+0x58/0xa8
[ 2305.830556] __arm64_sys_newfstatat+0x28/0x40
[ 2305.834901] invoke_syscall.constprop.0+0x80/0xd8
[ 2305.839592] do_el0_svc+0x48/0xd0
[ 2305.842894] el0_svc+0x4c/0x1c0
[ 2305.846023] el0t_64_sync_handler+0x120/0x130
[ 2305.850367] el0t_64_sync+0x1a4/0x1a8
[ 2305.854017] Code: 00000000 00000000 00000000 00000000 (84c565f1)
[ 2305.860098] SMP: stopping secondary CPUs
[ 2305.865048] Starting crashdump kernel...
[ 2305.868958] Bye!
On Mon, Aug 28, 2023 at 6:43 PM Ming Lei <[email protected]> wrote:
>
> On Wed, Aug 23, 2023 at 4:47 PM Christian Brauner <[email protected]> wrote:
> >
> > On Wed, Aug 23, 2023 at 12:06:14PM +0800, Ming Lei wrote:
> > >
> > > Looks the issue is more related with vfs, so forward to vfs list.
> > >
> > > ----- Forwarded message from Changhui Zhong <[email protected]> -----
> > >
> > > Date: Wed, 23 Aug 2023 11:17:55 +0800
> > > From: Changhui Zhong <[email protected]>
> > > To: [email protected]
> > > Cc: Ming Lei <[email protected]>
> > > Subject: [bug report] WARNING: CPU: 121 PID: 93233 at fs/dcache.c:365 __dentry_kill+0x214/0x278
> > >
> > > Hello,
> > >
> > > triggered below warning issue with branch
> > > "
> > > Tree: mainline.kernel.org-clang
> > > Repository: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> > > @ master
> > > Commit Hash: 89bf6209cad66214d3774dac86b6bbf2aec6a30d
> > > Commit Name: v6.5-rc7-18-g89bf6209cad6
> > > Kernel information:
> > > Commit message: Merge tag 'devicetree-fixes-for-6.5-2' of
> > > git://git.kernel.org/pub/scm/linux/kernel/git/robh/linux
> > > "
> > > for more detail，please check
> > > https://datawarehouse.cki-project.org/kcidb/tests/9232643
> > >
> > > #modprobe scsi_debug virtual_gb=128
> > > #echo none > /sys/block/sdb/queue/scheduler
> > > #fio --bs=4k --ioengine=libaio --iodepth=1 --numjobs=4 --rw=randrw
> > > --name=sdb-libaio-randrw-4k --filename=/dev/sdb --direct=1 --size=60G
> > > --runtime=60
> >
> > Looking at this issue it seems unlikely that this is a vfs bug.
> > We should see this all over the place and specifically not just on arm64.
> >
> > The sequence here seems to be:
> >
> > echo 4 > /proc/sys/vm/drop_caches
> > rmmod scsi_debug > /dev/null 3>&1
> >
> > [ 3117.059778] WARNING: CPU: 121 PID: 93233 at fs/dcache.c:365 __dentry_kill+0x214/0x278
> > [ 3117.067601] Modules linked in: scsi_debug nvme nvme_core nvme_common null_blk pktcdvd ipmi_watchdog ipmi_poweroff rfkill sunrpc vfat fat acpi_ipmi ipmi_ssif arm_spe_pmu igb ipmi_devintf ipmi_msghandler arm_cmn arm_dmc620_pmu cppc_cpufreq arm_dsu_pmu acpi_tad loop fuse zram xfs crct10dif_ce polyval_ce polyval_generic ghash_ce sbsa_gwdt ast onboard_usb_hub i2c_algo_bit xgene_hwmon [last unloaded: scsi_debug]
> >
> > So my money is on some device that gets removed still having an
> > increased refcount and pinning the dentry. Immediate suspects would be:
> >
> > 7882541ca06d ("of/platform: increase refcount of fwnode")
> >
> > but that part is complete speculation on my part.
>
> BTW, just saw another panic on 6.5-rc7, still scsi_debug test on arm64:
>
> [ 959.371726] sr 50:0:0:0: Attached scsi generic sg1 type 5
> [ 959.603145] scsi 48:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 959.603155] scsi 50:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 959.603950] scsi 49:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 959.604052] scsi 49:0:0:0: Power-on or device reset occurred
> [ 959.609336] sr 49:0:0:0: [sr1] scsi-1 drive
> [ 959.611360] scsi 48:0:0:0: Power-on or device reset occurred
> [ 959.614540] Unable to handle kernel paging request at virtual
> address 65888c2e6fe694d5
> [ 959.614544] Mem abort info:
> [ 959.614545] ESR = 0x0000000096000004
> [ 959.614547] EC = 0x25: DABT (current EL), IL = 32 bits
> [ 959.614550] SET = 0, FnV = 0
> [ 959.614552] EA = 0, S1PTW = 0
> [ 959.614553] FSC = 0x04: level 0 translation fault
> [ 959.614555] Data abort info:
> [ 959.614556] ISV = 0, ISS = 0x00000004, ISS2 = 0x00000000
> [ 959.614559] CM = 0, WnR = 0, TnD = 0, TagAccess = 0
> [ 959.614561] GCS = 0, Overlay = 0, DirtyBit = 0, Xs = 0
> [ 959.614563] [65888c2e6fe694d5] address between user and kernel address ranges
> [ 959.614566] Internal error: Oops: 0000000096000004 [#1] SMP
> [ 959.614570] Modules linked in: pktcdvd scsi_debug ipmi_watchdog
> ipmi_poweroff rfkill sunrpc vfat fat acpi_ipmi ipmi_ssif arm_spe_pmu
> igb ipmi_devintf arm_cmn ipmi_msghandler arm_dmc620_pmu arm_dsu_pmu
> cppc_cpufreq acpi_tad loop fuse zram xfs nvme crct10dif_ce polyval_ce
> nvme_core polyval_generic ghash_ce sbsa_gwdt nvme_common ast
> onboard_usb_hub i2c_algo_bit xgene_hwmon [last unloaded: scsi_debug]
> [ 959.614620] CPU: 108 PID: 19529 Comm: check Not tainted 6.5.0-rc7 #1
> [ 959.614625] Hardware name: GIGABYTE R152-P31-00/MP32-AR1-00, BIOS
> F31n (SCP: 2.10.20220810) 09/30/2022
> [ 959.614627] pstate: 80400009 (Nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
> [ 959.614632] pc : d_alloc_parallel+0x140/0x440
> [ 959.614641] lr : d_alloc_parallel+0xcc/0x440
> [ 959.614646] sp : ffff80008a7d3290
> [ 959.614647] x29: ffff80008a7d3290 x28: ffff07ff8230c530 x27: 65888c2e6fe69565
> [ 959.614654] x26: ffffcb72eac9e1d0 x25: ffff80008a7d33d8 x24: ffff07ffa0fd3800
> [ 959.614659] x23: 00000000000003c0 x22: 000000007a701548 x21: ffffcb72eac9ffd0
> [ 959.614664] x20: ffff07ffa0fd35c0 x19: ffffcb72ea6e9600 x18: ffffffffffffffff
> [ 959.614670] x17: 00000000440fd8e0 x16: 00000000b6431329 x15: ffff80008a7d3360
> [ 959.614675] x14: ffff80008a7d3508 x13: ffffcb72e94da6d0 x12: ffff80008a7d334c
> [ 959.614680] x11: 0000000c7a701548 x10: ffff3c8cb54590b8 x9 : ffffcb72e80832f4
> [ 959.614685] x8 : ffff07ffa0fd35c0 x7 : 7473696c5f71725f x6 : 0000000000200008
> [ 959.614690] x5 : ffffcb72ea6f4000 x4 : 00000000003d380a x3 : 0000000000000004
> [ 959.614696] x2 : ffff80008a7d331c x1 : ffff07ffe1760000 x0 : 0000000000005000
> [ 959.614701] Call trace:
> [ 959.614703] d_alloc_parallel+0x140/0x440
> [ 959.614708] __lookup_slow+0x64/0x158
> [ 959.614714] lookup_one_len+0xac/0xc8
> [ 959.614719] start_creating.part.0+0x88/0x198
> [ 959.614725] __debugfs_create_file+0x70/0x230
> [ 959.614730] debugfs_create_file+0x34/0x48
> [ 959.614734] blk_mq_debugfs_register_hctx+0x154/0x1d0
> [ 959.614740] blk_mq_debugfs_register+0xfc/0x1e0
> [ 959.614745] blk_register_queue+0xc0/0x1f0
> [ 959.614750] device_add_disk+0x1dc/0x3e0
> [ 959.614754] sr_probe+0x2c0/0x368
> [ 959.614760] really_probe+0x190/0x3d8
> [ 959.614766] __driver_probe_device+0x84/0x180
> [ 959.614771] driver_probe_device+0x44/0x120
> [ 959.614776] __device_attach_driver+0xc4/0x168
> [ 959.614781] bus_for_each_drv+0x8c/0xf0
> [ 959.614785] __device_attach+0xa4/0x1c0
> [ 959.614790] device_initial_probe+0x1c/0x30
> [ 959.614795] bus_probe_device+0xb4/0xc0
> [ 959.614799] device_add+0x508/0x6f8
> [ 959.614803] scsi_sysfs_add_sdev+0x8c/0x250
> [ 959.614809] scsi_add_lun+0x424/0x558
> [ 959.614813] scsi_probe_and_add_lun+0x11c/0x430
> [ 959.614817] __scsi_scan_target+0xb8/0x258
> [ 959.614821] scsi_scan_channel+0xa0/0xb8
> [ 959.614825] scsi_scan_host_selected+0x170/0x188
> [ 959.614830] store_scan+0x194/0x1a8
> [ 959.614835] dev_attr_store+0x20/0x40
> [ 959.614840] sysfs_kf_write+0x4c/0x68
> [ 959.614845] kernfs_fop_write_iter+0x13c/0x1d8
> [ 959.614849] vfs_write+0x1c0/0x310
> [ 959.614855] ksys_write+0x78/0x118
> [ 959.614859] __arm64_sys_write+0x24/0x38
> [ 959.614864] invoke_syscall+0x78/0x100
> [ 959.614868] el0_svc_common.constprop.0+0x4c/0xf8
> [ 959.614871] do_el0_svc+0x34/0x50
> [ 959.614874] el0_svc+0x34/0x108
> [ 959.614879] el0t_64_sync_handler+0x120/0x130
> [ 959.614884] el0t_64_sync+0x194/0x198
> [ 959.614889] Code: 54000088 14000067 f940037b b4000cbb (b8570360)
> [ 959.614892] ---[ end trace 0000000000000000 ]---
> [ 959.614895] Kernel panic - not syncing: Oops: Fatal exception
> [ 959.614897] SMP: stopping secondary CPUs
> [ 959.619492] Kernel Offset: 0x4b7267c40000 from 0xffff800080000000
> [ 959.619494] PHYS_OFFSET: 0x80000000
> [ 959.619496] CPU features: 0x00000010,b80140a1,8841720b
> [ 959.619498] Memory Limit: none
> [ 960.040819] ---[ end Kernel panic - not syncing: Oops: Fatal exception ]---
>
--
Best Regards,
Yi Zhang
On 2023/9/13 16:59, Yi Zhang wrote:
> The issue still can be reproduced on the latest linux tree[2].
> To reproduce I need to run about 1000 times blktests block/001, and
> bisect shows it was introduced with commit[1], as it was not 100%
> reproduced, not sure if it's the culprit?
>
>
> [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
Hello, everyone！
We have confirmed that the merge-in of this patch caused hlist_bl_lock
(aka, bit_spin_lock) to fail, which in turn triggered the issue above.
The process in which VFS issue arise is as follows:
1. bl_head >>> first==dentry2 >>> dentry1
dentry2->next = dentry1
dentry2->pprev = head
dentry1->next = NULL
dentry1->pprev = dentry2
2. Concurrent deletion of dentry, hlist_bl_lock lock protection failure
```
__hlist_bl_del(dentry2)
__hlist_bl_del(dentry1)
dentry2->next = NULL;
dentry1->next = NULL;
dentry1->pprev = NULL;
head->first = dentry1
dentry1->pprev = head
dentry2->next = NULL;
dentry2->pprev = NULL;
```
3. WARN_ON/BUG_ON is triggered because dentry1 is still on the
hlist after being deleted.
dentry1->next = NULL
dentry1->pprev = head
Verify that hlist_bl_lock is not working with the following mod：
mymod.c
```
#include <linux/kallsyms.h>
#include <linux/module.h>
#include <linux/moduleloader.h>
#include <linux/kernel.h>
#include <linux/jiffies.h>
#include <linux/sched.h>
#include <linux/smp.h>
#include <linux/cpu.h>
#include <linux/delay.h>
#include <linux/percpu.h>
#include <linux/threads.h>
#include <linux/kthread.h>
#include <linux/kernel_stat.h>
#include <linux/version.h>
#include <linux/slab.h>
#include <linux/smpboot.h>
#include <linux/pagemap.h>
#include <linux/notifier.h>
#include <linux/syscalls.h>
#include <linux/namei.h>
#include <asm/atomic.h>
#include <asm/bitops.h>
static unsigned long long a = 0, b = 0;
static struct hlist_bl_head bl_head;
struct task_struct *Thread1;
struct task_struct *Thread2;
struct task_struct *Thread3;
struct task_struct *Thread4;
struct task_struct *Thread5;
struct task_struct *Thread6;
int increase_ab(void *arg);
int increase_ab(void *arg)
{
while (1) {
hlist_bl_lock(&bl_head);
if (a != b) {
pr_err(">>> a = %llu, b = %llu \n", a, b);
BUG();
return -1;
}
if (a > (ULLONG_MAX - 4096)) {
a = 0;
b = 0;
}
a++;
b++;
hlist_bl_unlock(&bl_head);
schedule();
}
return 0;
}
static int mymod_init(void)
{
INIT_HLIST_BL_HEAD(&bl_head);
Thread1 = kthread_create(increase_ab, NULL, "bl_lock_thread1");
wake_up_process(Thread1);
Thread2 = kthread_create(increase_ab, NULL, "bl_lock_thread2");
wake_up_process(Thread2);
Thread3 = kthread_create(increase_ab, NULL, "bl_lock_thread3");
wake_up_process(Thread3);
Thread4 = kthread_create(increase_ab, NULL, "bl_lock_thread4");
wake_up_process(Thread4);
Thread5 = kthread_create(increase_ab, NULL, "bl_lock_thread5");
wake_up_process(Thread5);
Thread6 = kthread_create(increase_ab, NULL, "bl_lock_thread6");
wake_up_process(Thread6);
return 0;
}
static void mymod_exit(void)
{
if (Thread1)
kthread_stop(Thread1);
if (Thread2)
kthread_stop(Thread2);
if (Thread3)
kthread_stop(Thread3);
if (Thread4)
kthread_stop(Thread4);
if (Thread5)
kthread_stop(Thread5);
if (Thread6)
kthread_stop(Thread6);
}
module_init(mymod_init);
module_exit(mymod_exit);
MODULE_LICENSE("Dual BSD/GPL");
```
After 9257959a6e5b ("locking/atomic: scripts: restructure fallback
ifdeffery") is
merged in, we can see the problem when inserting the ko:
```
[root@localhost ~]# insmod mymod.ko
[ 37.994787][ T621] >>> a = 725, b = 724
[ 37.995313][ T621] ------------[ cut here ]------------
[ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
[r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
00000000f2000800 [#1] SMP
[ 37.997420][ T621] Modules linked in: mymod(E)
[ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
[ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
[ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT
-SSBS BTYPE=--)
[ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
[ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
[ 38.001416][ T621] sp : ffff800008b4be40
[ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
0000000000000000
[ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
0000000000000000
[ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
0000000000000001
[ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
0000000000000000
[ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
ffffffffffffffff
[ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
ffffd99332175b80
[ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
ffffd9933022a9d8
[ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
ffffd993320b5b40
[ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
0000000000000000
[ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
0000000000000015
[ 38.009709][ T621] Call trace:
[ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
[ 38.010539][ T621] kthread+0xdc/0xf0
[ 38.010927][ T621] ret_from_fork+0x10/0x20
[ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
[ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
[ 38.012603][ T621] Kernel panic - not syncing: Oops - BUG: Fatal
exception
[ 38.013311][ T621] SMP: stopping secondary CPUs
[ 38.013818][ T621] Kernel Offset: 0x599328000000 from 0xffff800008000000
[ 38.014508][ T621] PHYS_OFFSET: 0x40000000
[ 38.014933][ T621] CPU features: 0x000000,0220080c,44016203
[ 38.015510][ T621] Memory Limit: none
[ 38.015950][ T621] ---[ end Kernel panic - not syncing: Oops - BUG:
Fatal exception ]---
```
On Wed, Sep 13, 2023 at 04:59:31PM +0800, Yi Zhang wrote:
> The issue still can be reproduced on the latest linux tree[2].
> To reproduce I need to run about 1000 times blktests block/001, and
> bisect shows it was introduced with commit[1], as it was not 100%
> reproduced, not sure if it's the culprit?
>
>
> [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> [2]
> [ 2304.536339] scsi 48:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.540805] sr 50:0:0:0: Attached scsi CD-ROM sr3
> [ 2304.544574] scsi 48:0:0:0: Power-on or device reset occurred
> [ 2304.600645] sr 48:0:0:0: [sr1] scsi-1 drive
> [ 2304.616364] scsi 51:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.624639] scsi 51:0:0:0: Power-on or device reset occurred
> [ 2304.626634] sr 48:0:0:0: Attached scsi CD-ROM sr1
> [ 2304.680537] sr 51:0:0:0: [sr2] scsi-1 drive
> [ 2304.706394] sr 51:0:0:0: Attached scsi CD-ROM sr2
> [ 2304.746329] scsi 49:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.754569] scsi 49:0:0:0: Power-on or device reset occurred
> [ 2304.756302] scsi 50:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.768483] scsi 50:0:0:0: Power-on or device reset occurred
> [ 2304.806321] scsi 48:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.810587] sr 49:0:0:0: [sr0] scsi-1 drive
> [ 2304.814561] scsi 48:0:0:0: Power-on or device reset occurred
> [ 2304.824475] sr 50:0:0:0: [sr3] scsi-1 drive
> [ 2304.836384] scsi 51:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2304.840364] sr 49:0:0:0: Attached scsi CD-ROM sr0
> [ 2304.844619] scsi 51:0:0:0: Power-on or device reset occurred
> [ 2304.850444] sr 50:0:0:0: Attached scsi CD-ROM sr3
> [ 2304.874563] sr 48:0:0:0: [sr1] scsi-1 drive
> [ 2304.900660] sr 51:0:0:0: [sr2] scsi-1 drive
> [ 2304.901506] sr 48:0:0:0: Attached scsi CD-ROM sr1
> [ 2304.926306] sr 51:0:0:0: Attached scsi CD-ROM sr2
> [ 2305.056432] scsi 50:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2305.056572] scsi 49:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2305.064635] scsi 50:0:0:0: Power-on or device reset occurred
> [ 2305.072821] scsi 49:0:0:0: Power-on or device reset occurred
> [ 2305.086286] scsi 51:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2305.086357] scsi 48:0:0:0: CD-ROM Linux scsi_debug
> 0191 PQ: 0 ANSI: 7
> [ 2305.094521] scsi 51:0:0:0: Power-on or device reset occurred
> [ 2305.102693] scsi 48:0:0:0: Power-on or device reset occurred
> [ 2305.128785] sr 50:0:0:0: [sr0] scsi-1 drive
> [ 2305.134445] sr 49:0:0:0: [sr1] scsi-1 drive
> [ 2305.154728] sr 50:0:0:0: Attached scsi CD-ROM sr0
> [ 2305.158607] sr 51:0:0:0: [sr2] scsi-1 drive
> [ 2305.160392] sr 49:0:0:0: Attached scsi CD-ROM sr1
> [ 2305.164254] sr 48:0:0:0: [sr3] scsi-1 drive
> [ 2305.184185] sr 51:0:0:0: Attached scsi CD-ROM sr2
> [ 2305.190086] sr 48:0:0:0: Attached scsi CD-ROM sr3
> [ 2305.555658] Unable to handle kernel execute from non-executable
> memory at virtual address ffffc61b656052e8
> [ 2305.565301] Mem abort info:
> [ 2305.568086] ESR = 0x000000008600000e
> [ 2305.571822] EC = 0x21: IABT (current EL), IL = 32 bits
> [ 2305.577123] SET = 0, FnV = 0
> [ 2305.580164] EA = 0, S1PTW = 0
> [ 2305.583292] FSC = 0x0e: level 2 permission fault
> [ 2305.588074] swapper pgtable: 4k pages, 48-bit VAs, pgdp=0000080731fa0000
> [ 2305.594761] [ffffc61b656052e8] pgd=1000080ffffff003,
> p4d=1000080ffffff003, pud=1000080fffffe003, pmd=0068080732e00f01
> [ 2305.605362] Internal error: Oops: 000000008600000e [#1] SMP
> [ 2305.610922] Modules linked in: scsi_debug sr_mod pktcdvd cdrom
> rfkill sunrpc vfat fat acpi_ipmi arm_spe_pmu ipmi_ssif ipmi_devintf
> ipmi_msghandler arm_cmn arm_dmc620_pmu arm_dsu_pmu cppc_cpufreq loop
> fuse zram xfs crct10dif_ce ghash_ce nvme sha2_ce nvme_core
> sha256_arm64 igb sha1_ce ast sbsa_gwdt nvme_common
> i2c_designware_platform i2c_algo_bit i2c_designware_core xgene_hwmon
> dm_mod [last unloaded: scsi_debug]
> [ 2305.647236] CPU: 85 PID: 1 Comm: systemd Kdump: loaded Not tainted
> 6.6.0-rc1+ #13
> [ 2305.654706] Hardware name: GIGABYTE R152-P31-00/MP32-AR1-00, BIOS
> F31n (SCP: 2.10.20220810) 09/30/2022
> [ 2305.663997] pstate: 20400009 (nzCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
> [ 2305.670946] pc : in_lookup_hashtable+0x1138/0x2000
> [ 2305.675728] lr : rcu_do_batch+0x194/0x488
> [ 2305.679727] sp : ffff8000802abe60
> [ 2305.683029] x29: ffff8000802abe60 x28: ffffc61b6524c7c0 x27: ffffc61b63452f40
> [ 2305.690152] x26: ffff080f37ab6438 x25: 000000000000000a x24: 0000000000000000
> [ 2305.697274] x23: 0000000000000002 x22: ffff8000802abec0 x21: ffff080f37ab63c0
> [ 2305.704396] x20: ffff07ff8136a580 x19: 0000000000000003 x18: 0000000000000000
> [ 2305.711519] x17: ffff41f3d3161000 x16: ffff8000802a8000 x15: 0000000000000000
> [ 2305.718641] x14: 0000000000000000 x13: ffff07ffa131802d x12: ffff80008041bb94
> [ 2305.725764] x11: 0000000000000040 x10: ffff07ff802622e8 x9 : ffffc61b63452e30
> [ 2305.732887] x8 : 000002189dce1780 x7 : ffff07ff8d5c1000 x6 : ffff41f3d3161000
> [ 2305.740009] x5 : ffff07ff8136a580 x4 : ffff080f37aba960 x3 : 000000001550a055
> [ 2305.747131] x2 : 0000000000000000 x1 : ffffc61b656052e8 x0 : ffff080184c565f0
> [ 2305.754254] Call trace:
> [ 2305.756687] in_lookup_hashtable+0x1138/0x2000
> [ 2305.761119] rcu_core+0x268/0x350
> [ 2305.764422] rcu_core_si+0x18/0x30
> [ 2305.767812] __do_softirq+0x120/0x3d4
> [ 2305.771462] ____do_softirq+0x18/0x30
> [ 2305.775112] call_on_irq_stack+0x24/0x30
> [ 2305.779022] do_softirq_own_stack+0x24/0x38
> [ 2305.783192] __irq_exit_rcu+0xfc/0x130
> [ 2305.786929] irq_exit_rcu+0x18/0x30
> [ 2305.790404] el1_interrupt+0x4c/0xe8
> [ 2305.793969] el1h_64_irq_handler+0x18/0x28
> [ 2305.798052] el1h_64_irq+0x78/0x80
> [ 2305.801441] d_same_name+0x50/0xd0
> [ 2305.804832] __lookup_slow+0x64/0x158
> [ 2305.808482] walk_component+0xe0/0x1a0
> [ 2305.812219] path_lookupat+0x7c/0x1b8
> [ 2305.815869] filename_lookup+0xb4/0x1b8
> [ 2305.819692] vfs_statx+0x94/0x1a8
> [ 2305.822995] vfs_fstatat+0xd4/0x110
> [ 2305.826471] __do_sys_newfstatat+0x58/0xa8
> [ 2305.830556] __arm64_sys_newfstatat+0x28/0x40
> [ 2305.834901] invoke_syscall.constprop.0+0x80/0xd8
> [ 2305.839592] do_el0_svc+0x48/0xd0
> [ 2305.842894] el0_svc+0x4c/0x1c0
> [ 2305.846023] el0t_64_sync_handler+0x120/0x130
> [ 2305.850367] el0t_64_sync+0x1a4/0x1a8
> [ 2305.854017] Code: 00000000 00000000 00000000 00000000 (84c565f1)
> [ 2305.860098] SMP: stopping secondary CPUs
> [ 2305.865048] Starting crashdump kernel...
> [ 2305.868958] Bye!
>
>
Please don't top-post; reply inline with appropriate context instead.
Anyway, thanks for bisecting this regression. I'm adding it to regzbot:
#regzbot ^introduced: 9257959a6e5b4f
#regzbot title: restructuring atomic locking conditionals causes vfs dentry lock protection failure
--
An old man doll... just what I always wanted! - Clara
On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
> On 2023/9/13 16:59, Yi Zhang wrote:
> > The issue still can be reproduced on the latest linux tree[2].
> > To reproduce I need to run about 1000 times blktests block/001, and
> > bisect shows it was introduced with commit[1], as it was not 100%
> > reproduced, not sure if it's the culprit?
> >
> >
> > [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> Hello, everyone！
>
> We have confirmed that the merge-in of this patch caused hlist_bl_lock
> (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
> [root@localhost ~]# insmod mymod.ko
> [ 37.994787][ T621] >>> a = 725, b = 724
> [ 37.995313][ T621] ------------[ cut here ]------------
> [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
> [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
> 00000000f2000800 [#1] SMP
> [ 37.997420][ T621] Modules linked in: mymod(E)
> [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
> G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
> [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
> [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
> BTYPE=--)
> [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
> [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
> [ 38.001416][ T621] sp : ffff800008b4be40
> [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
> 0000000000000000
> [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
> 0000000000000000
> [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
> 0000000000000001
> [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
> 0000000000000000
> [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
> ffffffffffffffff
> [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
> ffffd99332175b80
> [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
> ffffd9933022a9d8
> [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
> ffffd993320b5b40
> [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
> 0000000000000000
> [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
> 0000000000000015
> [ 38.009709][ T621] Call trace:
> [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
> [ 38.010539][ T621] kthread+0xdc/0xf0
> [ 38.010927][ T621] ret_from_fork+0x10/0x20
> [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
> [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
Is this arm64 or something? You seem to have forgotten to mention what
platform you're using.
On Sun, Sep 17, 2023 at 11:10:32AM +0200, Peter Zijlstra wrote:
> On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
> > On 2023/9/13 16:59, Yi Zhang wrote:
> > > The issue still can be reproduced on the latest linux tree[2].
> > > To reproduce I need to run about 1000 times blktests block/001, and
> > > bisect shows it was introduced with commit[1], as it was not 100%
> > > reproduced, not sure if it's the culprit?
> > >
> > >
> > > [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> > Hello, everyone！
> >
> > We have confirmed that the merge-in of this patch caused hlist_bl_lock
> > (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
>
> > [root@localhost ~]# insmod mymod.ko
> > [ 37.994787][ T621] >>> a = 725, b = 724
> > [ 37.995313][ T621] ------------[ cut here ]------------
> > [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
> > [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
> > 00000000f2000800 [#1] SMP
> > [ 37.997420][ T621] Modules linked in: mymod(E)
> > [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
> > G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
> > [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
> > [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
> > BTYPE=--)
> > [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
> > [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
> > [ 38.001416][ T621] sp : ffff800008b4be40
> > [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
> > 0000000000000000
> > [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
> > 0000000000000000
> > [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
> > 0000000000000001
> > [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
> > 0000000000000000
> > [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
> > ffffffffffffffff
> > [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
> > ffffd99332175b80
> > [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
> > ffffd9933022a9d8
> > [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
> > ffffd993320b5b40
> > [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
> > 0000000000000000
> > [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
> > 0000000000000015
> > [ 38.009709][ T621] Call trace:
> > [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
> > [ 38.010539][ T621] kthread+0xdc/0xf0
> > [ 38.010927][ T621] ret_from_fork+0x10/0x20
> > [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
> > [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
>
> Is this arm64 or something? You seem to have forgotten to mention what
> platform you're using.
Is that an LSE or LLSC arm64 ?
Anyway, it seems that ARM64 shouldn't be using the fallback as it does
everything itself.
Mark, can you have a look please? At first glance the
atomic64_fetch_or_acquire() that's being used by generic bitops/lock.h
seems in order..
On 2023/9/17 17:10, Peter Zijlstra wrote:
> On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
>> On 2023/9/13 16:59, Yi Zhang wrote:
>>> The issue still can be reproduced on the latest linux tree[2].
>>> To reproduce I need to run about 1000 times blktests block/001, and
>>> bisect shows it was introduced with commit[1], as it was not 100%
>>> reproduced, not sure if it's the culprit?
>>>
>>>
>>> [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
>> Hello, everyone！
>>
>> We have confirmed that the merge-in of this patch caused hlist_bl_lock
>> (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
>> [root@localhost ~]# insmod mymod.ko
>> [ 37.994787][ T621] >>> a = 725, b = 724
>> [ 37.995313][ T621] ------------[ cut here ]------------
>> [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
>> [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
>> 00000000f2000800 [#1] SMP
>> [ 37.997420][ T621] Modules linked in: mymod(E)
>> [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
>> G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
>> [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
>> [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
>> BTYPE=--)
>> [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
>> [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
>> [ 38.001416][ T621] sp : ffff800008b4be40
>> [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
>> 0000000000000000
>> [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
>> 0000000000000000
>> [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
>> 0000000000000001
>> [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
>> 0000000000000000
>> [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
>> ffffffffffffffff
>> [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
>> ffffd99332175b80
>> [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
>> ffffd9933022a9d8
>> [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
>> ffffd993320b5b40
>> [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
>> 0000000000000000
>> [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
>> 0000000000000015
>> [ 38.009709][ T621] Call trace:
>> [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
>> [ 38.010539][ T621] kthread+0xdc/0xf0
>> [ 38.010927][ T621] ret_from_fork+0x10/0x20
>> [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
>> [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
> Is this arm64 or something? You seem to have forgotten to mention what
> platform you're using.
>
Sorry for the late reply.
We tested both x86 and arm64, and the problem is only encountered under
arm64.
--
With Best Regards,
Baokun Li
.
On 2023/9/17 17:26, Peter Zijlstra wrote:
> On Sun, Sep 17, 2023 at 11:10:32AM +0200, Peter Zijlstra wrote:
>> On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
>>> On 2023/9/13 16:59, Yi Zhang wrote:
>>>> The issue still can be reproduced on the latest linux tree[2].
>>>> To reproduce I need to run about 1000 times blktests block/001, and
>>>> bisect shows it was introduced with commit[1], as it was not 100%
>>>> reproduced, not sure if it's the culprit?
>>>>
>>>>
>>>> [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
>>> Hello, everyone！
>>>
>>> We have confirmed that the merge-in of this patch caused hlist_bl_lock
>>> (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
>>> [root@localhost ~]# insmod mymod.ko
>>> [ 37.994787][ T621] >>> a = 725, b = 724
>>> [ 37.995313][ T621] ------------[ cut here ]------------
>>> [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
>>> [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
>>> 00000000f2000800 [#1] SMP
>>> [ 37.997420][ T621] Modules linked in: mymod(E)
>>> [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
>>> G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
>>> [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
>>> [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
>>> BTYPE=--)
>>> [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
>>> [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
>>> [ 38.001416][ T621] sp : ffff800008b4be40
>>> [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
>>> 0000000000000000
>>> [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
>>> 0000000000000000
>>> [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
>>> 0000000000000001
>>> [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
>>> 0000000000000000
>>> [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
>>> ffffffffffffffff
>>> [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
>>> ffffd99332175b80
>>> [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
>>> ffffd9933022a9d8
>>> [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
>>> ffffd993320b5b40
>>> [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
>>> 0000000000000000
>>> [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
>>> 0000000000000015
>>> [ 38.009709][ T621] Call trace:
>>> [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
>>> [ 38.010539][ T621] kthread+0xdc/0xf0
>>> [ 38.010927][ T621] ret_from_fork+0x10/0x20
>>> [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
>>> [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
>> Is this arm64 or something? You seem to have forgotten to mention what
>> platform you're using.
> Is that an LSE or LLSC arm64 ?
I'm not sure how to distinguish if it's LSE or LLSC, here's some info on
the cpu:
$ cat /sys/devices/system/cpu/cpu0/regs/identification/midr_el1
0x00000000481fd010
$ lscpu
Architecture: aarch64
Byte Order: Little Endian
CPU(s): 96
On-line CPU(s) list: 0-95
Thread(s) per core: 1
Core(s) per socket: 48
Socket(s): 2
NUMA node(s): 4
Vendor ID: HiSilicon
BIOS Vendor ID: HiSilicon
Model: 0
Model name: Kunpeng-920
BIOS Model name: Kunpeng 920-4826
Stepping: 0x1
BogoMIPS: 200.00
L1d cache: 64K
L1i cache: 64K
L2 cache: 512K
L3 cache: 49152K
NUMA node0 CPU(s): 0-23
NUMA node1 CPU(s): 24-47
NUMA node2 CPU(s): 48-71
NUMA node3 CPU(s): 72-95
Flags: fp asimd evtstrm aes pmull sha1 sha2 crc32 atomics
fphp asimdhp cpuid asimdrdm jscvt fcma dcpop asimddp asimdfhm
> Anyway, it seems that ARM64 shouldn't be using the fallback as it does
> everything itself.
>
> Mark, can you have a look please? At first glance the
> atomic64_fetch_or_acquire() that's being used by generic bitops/lock.h
> seems in order..
>
We also suspect some implicit mechanism change in
raw_atomic64_fetch_or_acquire. You can reproduce the problem with the
above mod that can reproduce the problem to make it easier to locate.
I can help reproduce it and grab some information if you can't reproduce
it on your end.
--
With Best Regards,
Baokun Li
.
On Mon, Sep 18, 2023 at 9:10 AM Baokun Li <[email protected]> wrote:
>
> On 2023/9/17 17:10, Peter Zijlstra wrote:
> > On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
> >> On 2023/9/13 16:59, Yi Zhang wrote:
> >>> The issue still can be reproduced on the latest linux tree[2].
> >>> To reproduce I need to run about 1000 times blktests block/001, and
> >>> bisect shows it was introduced with commit[1], as it was not 100%
> >>> reproduced, not sure if it's the culprit?
> >>>
> >>>
> >>> [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> >> Hello, everyone！
> >>
> >> We have confirmed that the merge-in of this patch caused hlist_bl_lock
> >> (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
> >> [root@localhost ~]# insmod mymod.ko
> >> [ 37.994787][ T621] >>> a = 725, b = 724
> >> [ 37.995313][ T621] ------------[ cut here ]------------
> >> [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
> >> [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
> >> 00000000f2000800 [#1] SMP
> >> [ 37.997420][ T621] Modules linked in: mymod(E)
> >> [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
> >> G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
> >> [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
> >> [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
> >> BTYPE=--)
> >> [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
> >> [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
> >> [ 38.001416][ T621] sp : ffff800008b4be40
> >> [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
> >> 0000000000000000
> >> [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
> >> 0000000000000000
> >> [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
> >> 0000000000000001
> >> [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
> >> 0000000000000000
> >> [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
> >> ffffffffffffffff
> >> [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
> >> ffffd99332175b80
> >> [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
> >> ffffd9933022a9d8
> >> [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
> >> ffffd993320b5b40
> >> [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
> >> 0000000000000000
> >> [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
> >> 0000000000000015
> >> [ 38.009709][ T621] Call trace:
> >> [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
> >> [ 38.010539][ T621] kthread+0xdc/0xf0
> >> [ 38.010927][ T621] ret_from_fork+0x10/0x20
> >> [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
> >> [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
> > Is this arm64 or something? You seem to have forgotten to mention what
> > platform you're using.
> >
> Sorry for the late reply.
> We tested both x86 and arm64, and the problem is only encountered under
> arm64.
Yeah, my reproduced environment is also aarch64.
>
> --
> With Best Regards,
> Baokun Li
> .
>
--
Best Regards,
Yi Zhang
On Mon, Sep 18, 2023 at 09:52:28AM +0800, Baokun Li wrote:
> On 2023/9/17 17:26, Peter Zijlstra wrote:
> > On Sun, Sep 17, 2023 at 11:10:32AM +0200, Peter Zijlstra wrote:
> > > On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
> > > > On 2023/9/13 16:59, Yi Zhang wrote:
> > > > > The issue still can be reproduced on the latest linux tree[2].
> > > > > To reproduce I need to run about 1000 times blktests block/001, and
> > > > > bisect shows it was introduced with commit[1], as it was not 100%
> > > > > reproduced, not sure if it's the culprit?
> > > > >
> > > > >
> > > > > [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> > > > Hello, everyone！
> > > >
> > > > We have confirmed that the merge-in of this patch caused hlist_bl_lock
> > > > (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
> > > > [root@localhost ~]# insmod mymod.ko
> > > > [ 37.994787][ T621] >>> a = 725, b = 724
> > > > [ 37.995313][ T621] ------------[ cut here ]------------
> > > > [ 37.995951][ T621] kernel BUG at fs/mymod/mymod.c:42!
> > > > [r[ oo [email protected]]h[o s T6t21] ~ ]#Int ernal error: Oops - BUG:
> > > > 00000000f2000800 [#1] SMP
> > > > [ 37.997420][ T621] Modules linked in: mymod(E)
> > > > [ 37.997891][ T621] CPU: 9 PID: 621 Comm: bl_lock_thread2 Tainted:
> > > > G E 6.4.0-rc2-00034-g9257959a6e5b-dirty #117
> > > > [ 37.999038][ T621] Hardware name: linux,dummy-virt (DT)
> > > > [ 37.999571][ T621] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS
> > > > BTYPE=--)
> > > > [ 38.000344][ T621] pc : increase_ab+0xcc/0xe70 [mymod]
> > > > [ 38.000882][ T621] lr : increase_ab+0xcc/0xe70 [mymod]
> > > > [ 38.001416][ T621] sp : ffff800008b4be40
> > > > [ 38.001822][ T621] x29: ffff800008b4be40 x28: 0000000000000000 x27:
> > > > 0000000000000000
> > > > [ 38.002605][ T621] x26: 0000000000000000 x25: 0000000000000000 x24:
> > > > 0000000000000000
> > > > [ 38.003385][ T621] x23: ffffd9930c698190 x22: ffff800008a0ba38 x21:
> > > > 0000000000000001
> > > > [ 38.004174][ T621] x20: ffffffffffffefff x19: ffffd9930c69a580 x18:
> > > > 0000000000000000
> > > > [ 38.004955][ T621] x17: 0000000000000000 x16: ffffd9933011bd38 x15:
> > > > ffffffffffffffff
> > > > [ 38.005754][ T621] x14: 0000000000000000 x13: 205d313236542020 x12:
> > > > ffffd99332175b80
> > > > [ 38.006538][ T621] x11: 0000000000000003 x10: 0000000000000001 x9 :
> > > > ffffd9933022a9d8
> > > > [ 38.007325][ T621] x8 : 00000000000bffe8 x7 : c0000000ffff7fff x6 :
> > > > ffffd993320b5b40
> > > > [ 38.008124][ T621] x5 : ffff0001f7d1c708 x4 : 0000000000000000 x3 :
> > > > 0000000000000000
> > > > [ 38.008912][ T621] x2 : 0000000000000000 x1 : 0000000000000000 x0 :
> > > > 0000000000000015
> > > > [ 38.009709][ T621] Call trace:
> > > > [ 38.010035][ T621] increase_ab+0xcc/0xe70 [mymod]
> > > > [ 38.010539][ T621] kthread+0xdc/0xf0
> > > > [ 38.010927][ T621] ret_from_fork+0x10/0x20
> > > > [ 38.011370][ T621] Code: 17ffffe0 90000020 91044000 9400000d (d4210000)
> > > > [ 38.012067][ T621] ---[ end trace 0000000000000000 ]---
> > > Is this arm64 or something? You seem to have forgotten to mention what
> > > platform you're using.
> > Is that an LSE or LLSC arm64 ?
>
> I'm not sure how to distinguish if it's LSE or LLSC, here's some info on the
> cpu:
>
> $ cat /sys/devices/system/cpu/cpu0/regs/identification/midr_el1
> 0x00000000481fd010
>
> $ lscpu
> Architecture: aarch64
> Byte Order: Little Endian
> CPU(s): 96
> On-line CPU(s) list: 0-95
> Thread(s) per core: 1
> Core(s) per socket: 48
> Socket(s): 2
> NUMA node(s): 4
> Vendor ID: HiSilicon
> BIOS Vendor ID: HiSilicon
> Model: 0
> Model name: Kunpeng-920
> BIOS Model name: Kunpeng 920-4826
> Stepping: 0x1
> BogoMIPS: 200.00
> L1d cache: 64K
> L1i cache: 64K
> L2 cache: 512K
> L3 cache: 49152K
> NUMA node0 CPU(s): 0-23
> NUMA node1 CPU(s): 24-47
> NUMA node2 CPU(s): 48-71
> NUMA node3 CPU(s): 72-95
> Flags: fp asimd evtstrm aes pmull sha1 sha2 crc32 atomics fphp
> asimdhp cpuid asimdrdm jscvt fcma dcpop asimddp asimdfhm
>
> > Anyway, it seems that ARM64 shouldn't be using the fallback as it does
> > everything itself.
> >
> > Mark, can you have a look please? At first glance the
> > atomic64_fetch_or_acquire() that's being used by generic bitops/lock.h
> > seems in order..
> >
> We also suspect some implicit mechanism change in
> raw_atomic64_fetch_or_acquire. You can reproduce the problem with the
> above mod that can reproduce the problem to make it easier to locate.
> I can help reproduce it and grab some information if you can't reproduce
> it on your end.
FWIW this looks a lot like the crash I reported last week:
https://lore.kernel.org/linux-fsdevel/ZQep0OR0uMmR%[email protected]/T/#t
Also arm64, but virtualized. I /think/ the host is some Ampere box,
though I have no idea what kind since it's just some Oracle Cloud A1
instance. The internet claims "Ampere Altra" processors[1].
# lscpu
Architecture: aarch64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 2
On-line CPU(s) list: 0,1
Vendor ID: ARM
Model name: Neoverse-N1
Model: 1
Thread(s) per core: 1
Core(s) per socket: 2
Socket(s): 1
Stepping: r3p1
BogoMIPS: 50.00
Flags: fp asimd evtstrm aes pmull sha1 sha2 crc32
atomics fphp asimdhp cpuid asimdrdm lrcpc dcpop asimddp ssbs
NUMA:
NUMA node(s): 1
NUMA node0 CPU(s): 0,1
Vulnerabilities:
Gather data sampling: Not affected
Itlb multihit: Not affected
L1tf: Not affected
Mds: Not affected
Meltdown: Not affected
Mmio stale data: Not affected
Retbleed: Not affected
Spec rstack overflow: Not affected
Spec store bypass: Vulnerable
Spectre v1: Mitigation; __user pointer sanitization
Spectre v2: Mitigation; CSV2, but not BHB
Srbds: Not affected
Tsx async abort: Not affected
[1] https://www.oracle.com/cloud/compute/arm/
--D
> --
> With Best Regards,
> Baokun Li
> .
On Sat, Sep 16, 2023 at 02:55:47PM +0800, Baokun Li wrote:
> On 2023/9/13 16:59, Yi Zhang wrote:
> > The issue still can be reproduced on the latest linux tree[2].
> > To reproduce I need to run about 1000 times blktests block/001, and
> > bisect shows it was introduced with commit[1], as it was not 100%
> > reproduced, not sure if it's the culprit?
> >
> >
> > [1] 9257959a6e5b locking/atomic: scripts: restructure fallback ifdeffery
> Hello, everyone！
>
> We have confirmed that the merge-in of this patch caused hlist_bl_lock
> (aka, bit_spin_lock) to fail, which in turn triggered the issue above.
Thanks for this!
I believe I know what the issue is.
I took a look at the generated assembly for hlist_bl_lock() and
hlist_bl_unlock(), and for the latter I see a plain store rather than a
store-release as was intended.
I believe that in 9257959a6e5b, I messed up the fallback logic for
atomic*_set_release():
| static __always_inline void
| raw_atomic64_set_release(atomic64_t *v, s64 i)
| {
| #if defined(arch_atomic64_set_release)
| arch_atomic64_set_release(v, i);
| #elif defined(arch_atomic64_set)
| arch_atomic64_set(v, i);
| #else
| if (__native_word(atomic64_t)) {
| smp_store_release(&(v)->counter, i);
| } else {
| __atomic_release_fence();
| raw_atomic64_set(v, i);
| }
| #endif
| }
On arm64 we want to use smp_store_release(), and don't provide
arch_atomic64_set_release(). Unfortunately we *do* provide arch_atomic64_set(),
and the ifdeffery above will choose that in preference.
Prior to that commit, the ifdeffery would do what we want:
| #ifndef arch_atomic64_set_release
| static __always_inline void
| arch_atomic64_set_release(atomic64_t *v, s64 i)
| {
| if (__native_word(atomic64_t)) {
| smp_store_release(&(v)->counter, i);
| } else {
| __atomic_release_fence();
| arch_atomic64_set(v, i);
| }
| }
| #define arch_atomic64_set_release arch_atomic64_set_release
| #endif
That explains the lock going wrong -- we lose the RELEASE semantic on
hlist_bl_unlock(), and so loads and stores within the critical section aren't
guaranteed to be visible to the next hlist_bl_lock(). On x86 this happens to
work becauase of TSO.
I'm working on fixing that now; I'll try to have a patch shortly.
Thanks,
Mark.
On 17.09.23 02:35, Bagas Sanjaya wrote:
> On Wed, Sep 13, 2023 at 04:59:31PM +0800, Yi Zhang wrote:
>> The issue still can be reproduced on the latest linux tree[2].
>> To reproduce I need to run about 1000 times blktests block/001, and
>> bisect shows it was introduced with commit[1], as it was not 100%
>> reproduced, not sure if it's the culprit?
>
> Anyway, thanks for bisecting this regression. I'm adding it to regzbot:
>
> #regzbot ^introduced: 9257959a6e5b4f
> #regzbot title: restructuring atomic locking conditionals causes vfs dentry lock protection failure
#regzbot fix: 6d2779ecaeb56f
#regzbot ignore-activity
Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
--
Everything you wanna know about Linux kernel regression tracking:
https://linux-regtracking.leemhuis.info/about/#tldr
That page also explains what to do if mails like this annoy you.