2018-12-20 09:25:22

by kernel test robot

[permalink] [raw]
Subject: [ide] ec7d9c9ce8: WARNING:at_fs/proc/generic.c:#remove_proc_entry


FYI, we noticed the following commit (built with gcc-7):

commit: ec7d9c9ce897174243af4fcd201dbfc34df0f3a3 ("ide: replace ->proc_fops with ->proc_show")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

in testcase: rcutorture
with following parameters:

runtime: 300s
test: default

test-description: rcutorture is rcutorture kernel module load/unload test.
test-url: https://www.kernel.org/doc/Documentation/RCU/torture.txt


on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 768M

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-------------------------------------------------+------------+------------+
| | 61fb5c043f | ec7d9c9ce8 |
+-------------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 0 | 4 |
| WARNING:at_fs/proc/generic.c:#remove_proc_entry | 0 | 4 |
| RIP:remove_proc_entry | 0 | 4 |
+-------------------------------------------------+------------+------------+



[ 44.180514] WARNING: CPU: 1 PID: 165 at fs/proc/generic.c:662 remove_proc_entry+0xb9/0x155
[ 44.196842] Modules linked in: bochs_drm(+) ttm drm_kms_helper drm input_leds piix(+) serio_raw drm_panel_orientation_quirks ide_core evbug evdev
[ 44.217807] CPU: 1 PID: 165 Comm: udevd Not tainted 4.17.0-rc5-00040-gec7d9c9 #1
[ 44.229700] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 44.243024] RIP: 0010:remove_proc_entry+0xb9/0x155
[ 44.250863] RSP: 0018:ffffc9000020bab0 EFLAGS: 00010296
[ 44.259380] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffc9000020b93c
[ 44.270823] RDX: 0000000000000004 RSI: 0000000000000004 RDI: 0000000000000246
[ 44.282325] RBP: ffffffffa001e188 R08: 0000000000000008 R09: 0000000000000000
[ 44.293739] R10: ffff8800283ab2d9 R11: ffffffff82d20e07 R12: ffff88001ebec200
[ 44.305176] R13: ffffffffa0022180 R14: 0000000000000001 R15: 000000000000001b
[ 44.316678] FS: 00007f9d22f99780(0000) GS:ffff88002cb00000(0000) knlGS:0000000000000000
[ 44.329702] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 44.338938] CR2: 00007f9d2263e670 CR3: 000000001dc60000 CR4: 00000000000006e0
[ 44.350383] Call Trace:
[ 44.354594] ide_proc_unregister_device+0x19/0x53 [ide_core]
[ 44.364085] drive_release_dev+0x10/0x39 [ide_core]
[ 44.371964] device_release+0x53/0x7b
[ 44.377989] kobject_put+0x76/0x8d
[ 44.384015] __ide_port_unregister_devices+0x1d/0x43 [ide_core]
[ 44.393931] ide_host_remove+0x51/0x101 [ide_core]
[ 44.413087] ide_pci_remove+0x4f/0x81 [ide_core]
[ 44.420374] pci_device_remove+0x23/0x4d
[ 44.426440] driver_probe_device+0x18a/0x30f
[ 44.433112] __driver_attach+0x6b/0x8b
[ 44.439045] ? driver_probe_device+0x30f/0x30f
[ 44.445917] bus_for_each_dev+0x5f/0xa0
[ 44.452003] bus_add_driver+0xe4/0x1c9
[ 44.457812] driver_register+0x7d/0xaf
[ 44.463765] piix_ide_init+0xb1/0x1000 [piix]
[ 44.470604] ? fs_reclaim_release+0x9/0x22
[ 44.476925] ? 0xffffffffa004b000
[ 44.482171] do_one_initcall+0x6e/0x144
[ 44.488137] do_init_module+0x72/0x3b6
[ 44.493715] load_module+0x1c8b/0x1ec1
[ 44.499611] ? vfs_read+0xfe/0x10a
[ 44.504987] ? __se_sys_finit_module+0x90/0xb6
[ 44.511865] __se_sys_finit_module+0x90/0xb6
[ 44.518537] do_syscall_64+0xe7/0x16c
[ 44.524270] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 44.532115] RIP: 0033:0x7f9d2266e4a9
[ 44.537724] RSP: 002b:00007ffc4a1959c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 44.549316] RAX: ffffffffffffffda RBX: 0000000000647160 RCX: 00007f9d2266e4a9
[ 44.560147] RDX: 0000000000000000 RSI: 00007f9d2293a0aa RDI: 0000000000000008
[ 44.571101] RBP: 00007f9d2293a0aa R08: 0000000000000000 R09: 0000000000647160
[ 44.581960] R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000000000
[ 44.592881] R13: 0000000000020000 R14: 0000000000000000 R15: 0000000000647160
[ 44.603836] Code: 8d b8 a8 00 00 00 e8 53 32 54 00 48 c7 c7 60 e3 03 82 e8 e2 45 55 00 48 85 db 75 13 48 89 ee 48 c7 c7 8f 1b ec 81 e8 55 45 eb ff <0f> 0b eb 7a 48 89 df e8 d0 b4 ff ff 8b 83 c8 00 00 00 66 25 00
[ 44.633074] ---[ end trace d0fa34ec8e604638 ]---


To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Rong Chen


Attachments:
(No filename) (4.61 kB)
config-4.17.0-rc5-00040-gec7d9c9 (117.70 kB)
job-script (4.45 kB)
dmesg.xz (12.57 kB)
Download all attachments

2018-12-20 16:47:22

by Linus Torvalds

[permalink] [raw]
Subject: Re: [ide] ec7d9c9ce8: WARNING:at_fs/proc/generic.c:#remove_proc_entry

On Thu, Dec 20, 2018 at 1:19 AM kernel test robot <[email protected]> wrote:
>
> FYI, we noticed the following commit (built with gcc-7):
>
> commit: ec7d9c9ce897174243af4fcd201dbfc34df0f3a3 ("ide: replace ->proc_fops with ->proc_show")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

Funky. How did the kernel test robot suddenly figure out an 8-month
old problem?

> [ 44.180514] WARNING: CPU: 1 PID: 165 at fs/proc/generic.c:662 remove_proc_entry+0xb9/0x155

This is a warning for somebody doing "remove_proc_entry() on a name
that doesn't actually exist in that /proc directory.

In this case, it does seem to be due to the named commit adding a

+ remove_proc_entry("settings", drive->proc);

to ide_proc_unregister_device(), and looking at the patch I get the
feeling that it's due to a typo: the code *creates* the file called
"setting", but removes the file "settings". Note the missing "s" at
creation time.

And yes, the name of the /proc file _should_be "settings", judging by
the rest of the patch.

So it does seem to be a real bug. Nobody noticed until now? Why did
the test robot suddenly react to it?

Linus

2018-12-20 16:55:11

by Christoph Hellwig

[permalink] [raw]
Subject: Re: [ide] ec7d9c9ce8: WARNING:at_fs/proc/generic.c:#remove_proc_entry

On Thu, Dec 20, 2018 at 09:14:50AM -0700, Jens Axboe wrote:
> Maybe the the tiny subset of IDE users don't actually have the proc
> stuff enabled? A few months ago I did plenty of IDE testing with the
> MQ conversion, but I never saw anything like this. I'm guessing that
> I, too, did not have IDE_PROC_FS enabled.

Or the tiny subset of ide users basically doesn't exist and the
few platforms that use ide are basically bitrotting?

> Christoph, do you want to post the one-liner fix for this one?

See below:

--
From c3550c617ffc48079fe6364a4fa3c7f75a09028b Mon Sep 17 00:00:00 2001
From: Christoph Hellwig <[email protected]>
Date: Thu, 20 Dec 2018 17:16:53 +0100
Subject: ide: fix a typo in the settings proc file name

Fixes: ec7d9c9ce8 ("ide: replace ->proc_fops with ->proc_show")
Reported-by: kernel test robot <[email protected]>
Signed-off-by: Christoph Hellwig <[email protected]>
---
drivers/ide/ide-proc.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/ide/ide-proc.c b/drivers/ide/ide-proc.c
index 45c997430332..0e51803de0e7 100644
--- a/drivers/ide/ide-proc.c
+++ b/drivers/ide/ide-proc.c
@@ -544,7 +544,7 @@ void ide_proc_port_register_devices(ide_hwif_t *hwif)
drive->proc = proc_mkdir(drive->name, parent);
if (drive->proc) {
ide_add_proc_entries(drive->proc, generic_drive_entries, drive);
- proc_create_data("setting", S_IFREG|S_IRUSR|S_IWUSR,
+ proc_create_data("settings", S_IFREG|S_IRUSR|S_IWUSR,
drive->proc, &ide_settings_proc_fops,
drive);
}
--
2.19.2


2018-12-20 21:44:32

by Jens Axboe

[permalink] [raw]
Subject: Re: [ide] ec7d9c9ce8: WARNING:at_fs/proc/generic.c:#remove_proc_entry

On 12/20/18 9:05 AM, Linus Torvalds wrote:
> On Thu, Dec 20, 2018 at 1:19 AM kernel test robot <[email protected]> wrote:
>>
>> FYI, we noticed the following commit (built with gcc-7):
>>
>> commit: ec7d9c9ce897174243af4fcd201dbfc34df0f3a3 ("ide: replace ->proc_fops with ->proc_show")
>> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> Funky. How did the kernel test robot suddenly figure out an 8-month
> old problem?
>
>> [ 44.180514] WARNING: CPU: 1 PID: 165 at fs/proc/generic.c:662 remove_proc_entry+0xb9/0x155
>
> This is a warning for somebody doing "remove_proc_entry() on a name
> that doesn't actually exist in that /proc directory.
>
> In this case, it does seem to be due to the named commit adding a
>
> + remove_proc_entry("settings", drive->proc);
>
> to ide_proc_unregister_device(), and looking at the patch I get the
> feeling that it's due to a typo: the code *creates* the file called
> "setting", but removes the file "settings". Note the missing "s" at
> creation time.
>
> And yes, the name of the /proc file _should_be "settings", judging by
> the rest of the patch.
>
> So it does seem to be a real bug. Nobody noticed until now? Why did
> the test robot suddenly react to it?

Maybe the the tiny subset of IDE users don't actually have the proc
stuff enabled? A few months ago I did plenty of IDE testing with the
MQ conversion, but I never saw anything like this. I'm guessing that
I, too, did not have IDE_PROC_FS enabled.

Christoph, do you want to post the one-liner fix for this one?

--
Jens Axboe


2018-12-21 08:34:39

by Philip Li

[permalink] [raw]
Subject: Re: [LKP] [ide] ec7d9c9ce8: WARNING:at_fs/proc/generic.c:#remove_proc_entry

On Thu, Dec 20, 2018 at 08:05:28AM -0800, Linus Torvalds wrote:
> On Thu, Dec 20, 2018 at 1:19 AM kernel test robot <[email protected]> wrote:
> >
> > FYI, we noticed the following commit (built with gcc-7):
> >
> > commit: ec7d9c9ce897174243af4fcd201dbfc34df0f3a3 ("ide: replace ->proc_fops with ->proc_show")
> > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> Funky. How did the kernel test robot suddenly figure out an 8-month
> old problem?
Hi Linus, sorry for this late report. I can't figure out exact reason but some possible clues.

The issue is captured by rcutoture which doesn't work well before. And only from late october,
we have solved a few issues of the execution including the rootfs (yocto) it is using. And this issue
is against an randconfig, i'm not sure whether the issue depends on a certain kconfig thus only
be triggered or successfully bisected this time.

>
> > [ 44.180514] WARNING: CPU: 1 PID: 165 at fs/proc/generic.c:662 remove_proc_entry+0xb9/0x155
>
> This is a warning for somebody doing "remove_proc_entry() on a name
> that doesn't actually exist in that /proc directory.
>
> In this case, it does seem to be due to the named commit adding a
>
> + remove_proc_entry("settings", drive->proc);
>
> to ide_proc_unregister_device(), and looking at the patch I get the
> feeling that it's due to a typo: the code *creates* the file called
> "setting", but removes the file "settings". Note the missing "s" at
> creation time.
>
> And yes, the name of the /proc file _should_be "settings", judging by
> the rest of the patch.
>
> So it does seem to be a real bug. Nobody noticed until now? Why did
> the test robot suddenly react to it?
>
> Linus
> _______________________________________________
> LKP mailing list
> [email protected]
> https://lists.01.org/mailman/listinfo/lkp