2021-10-21 13:17:21

by Oliver Sang

[permalink] [raw]
Subject: [btrfs] 0f80799866: WARNING:at_fs/sysfs/file.c:#sysfs_emit



Greeting,

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

commit: 0f807998661ecadb74638c18cbaff8785bb46f8d ("[PATCH 1/2] btrfs: sysfs convert scnprintf and snprintf to use sysfs_emit")
url: https://github.com/0day-ci/linux/commits/Anand-Jain/provide-fsid-in-sysfs-devinfo/20211019-082356
base: https://git.kernel.org/cgit/linux/kernel/git/kdave/linux.git for-next

in testcase: boot

on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G

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


+----------------------------------------+------------+------------+
| | 00c9626f46 | 0f80799866 |
+----------------------------------------+------------+------------+
| boot_successes | 12 | 0 |
| boot_failures | 0 | 12 |
| WARNING:at_fs/sysfs/file.c:#sysfs_emit | 0 | 12 |
| EIP:sysfs_emit | 0 | 12 |
+----------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 17.140001][ T1] WARNING: CPU: 0 PID: 1 at fs/sysfs/file.c:737 sysfs_emit (fs/sysfs/file.c:737)
[ 17.141231][ T1] Modules linked in:
[ 17.141878][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.15.0-rc5-00151-g0f807998661e #2
[ 17.143180][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 17.144848][ T1] EIP: sysfs_emit (fs/sysfs/file.c:737)
[ 17.145557][ T1] Code: e8 76 ec 66 00 83 c4 08 5b 5d c3 ba 01 00 00 00 b8 00 fa 50 cc e8 d1 a9 e2 ff 89 5c 24 04 c7 04 24 b1 88 c7 cb e8 da 0d 14 01 <0f> 0b b8 e8 f9 50 cc 31 c9 c7 04 24 01 00 00 00 ba 01 00 00 00 e8
All code
========
0: e8 76 ec 66 00 callq 0x66ec7b
5: 83 c4 08 add $0x8,%esp
8: 5b pop %rbx
9: 5d pop %rbp
a: c3 retq
b: ba 01 00 00 00 mov $0x1,%edx
10: b8 00 fa 50 cc mov $0xcc50fa00,%eax
15: e8 d1 a9 e2 ff callq 0xffffffffffe2a9eb
1a: 89 5c 24 04 mov %ebx,0x4(%rsp)
1e: c7 04 24 b1 88 c7 cb movl $0xcbc788b1,(%rsp)
25: e8 da 0d 14 01 callq 0x1140e04
2a:* 0f 0b ud2 <-- trapping instruction
2c: b8 e8 f9 50 cc mov $0xcc50f9e8,%eax
31: 31 c9 xor %ecx,%ecx
33: c7 04 24 01 00 00 00 movl $0x1,(%rsp)
3a: ba 01 00 00 00 mov $0x1,%edx
3f: e8 .byte 0xe8

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: b8 e8 f9 50 cc mov $0xcc50f9e8,%eax
7: 31 c9 xor %ecx,%ecx
9: c7 04 24 01 00 00 00 movl $0x1,(%rsp)
10: ba 01 00 00 00 mov $0x1,%edx
15: e8 .byte 0xe8
[ 17.148128][ T1] EAX: 00000020 EBX: cce568e0 ECX: 00000000 EDX: 00000000
[ 17.149078][ T1] ESI: cce54ae0 EDI: cce568e0 EBP: c181fed4 ESP: c181fec8
[ 17.150009][ T1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010296
[ 17.151159][ T1] CR0: 80050033 CR2: 00000000 CR3: 0c709000 CR4: 000406d0
[ 17.152227][ T1] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 17.153237][ T1] DR6: fffe0ff0 DR7: 00000400
[ 17.153964][ T1] Call Trace:
[ 17.154511][ T1] btrfs_init_sysfs (fs/btrfs/sysfs.c:1310 fs/btrfs/sysfs.c:2023)
[ 17.155279][ T1] ? tracefs_create_instance_dir (fs/btrfs/super.c:2552)
[ 17.156161][ T1] init_btrfs_fs (fs/btrfs/super.c:2558)
[ 17.156848][ T1] do_one_initcall (init/main.c:1303)
[ 17.157551][ T1] ? parse_args (kernel/params.c:153 kernel/params.c:188)
[ 17.158265][ T1] ? __this_cpu_preempt_check (lib/smp_processor_id.c:67)
[ 17.159070][ T1] kernel_init_freeable (init/main.c:1375 init/main.c:1392 init/main.c:1411 init/main.c:1614)
[ 17.163787][ T1] ? rest_init (init/main.c:1497)
[ 17.171751][ T1] kernel_init (init/main.c:1507)
[ 17.172549][ T1] ? schedule_tail_wrapper (arch/x86/entry/entry_32.S:740)
[ 17.173320][ T1] ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 17.174042][ T1] irq event stamp: 2402249
[ 17.174752][ T1] hardirqs last enabled at (2402257): __up_console_sem (kernel/printk/printk.c:255 (discriminator 1))
[ 17.176070][ T1] hardirqs last disabled at (2402272): __up_console_sem (kernel/printk/printk.c:253 (discriminator 1))
[ 17.177397][ T1] softirqs last enabled at (2402270): __do_softirq (kernel/softirq.c:402 kernel/softirq.c:587)
[ 17.178704][ T1] softirqs last disabled at (2402265): do_softirq_own_stack (arch/x86/kernel/irq_32.c:60 arch/x86/kernel/irq_32.c:149)
[ 17.180238][ T1] ---[ end trace c9e9be0944a14324 ]---
[ 17.181055][ T1] ------------[ cut here ]------------
[ 17.184298][ T1] invalid sysfs_emit: buf:cce568ed


To reproduce:

# build kernel
cd linux
cp config-5.15.0-rc5-00151-g0f807998661e .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 olddefconfig prepare modules_prepare bzImage

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

# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (5.61 kB)
config-5.15.0-rc5-00151-g0f807998661e (159.31 kB)
job-script (4.89 kB)
dmesg.xz (46.32 kB)
Download all attachments

2021-10-21 15:33:57

by Anand Jain

[permalink] [raw]
Subject: Re: [btrfs] 0f80799866: WARNING:at_fs/sysfs/file.c:#sysfs_emit



On 21/10/2021 21:35, kernel test robot wrote:
>
>
> Greeting,
>
> FYI, we noticed the following commit (built with gcc-9):
>
> commit: 0f807998661ecadb74638c18cbaff8785bb46f8d ("[PATCH 1/2] btrfs: sysfs convert scnprintf and snprintf to use sysfs_emit")
> url: https://github.com/0day-ci/linux/commits/Anand-Jain/provide-fsid-in-sysfs-devinfo/20211019-082356
> base: https://git.kernel.org/cgit/linux/kernel/git/kdave/linux.git for-next
>
> in testcase: boot
>
> on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
> +----------------------------------------+------------+------------+
> | | 00c9626f46 | 0f80799866 |
> +----------------------------------------+------------+------------+
> | boot_successes | 12 | 0 |
> | boot_failures | 0 | 12 |
> | WARNING:at_fs/sysfs/file.c:#sysfs_emit | 0 | 12 |
> | EIP:sysfs_emit | 0 | 12 |
> +----------------------------------------+------------+------------+
>
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <[email protected]>
>
>
> [ 17.140001][ T1] WARNING: CPU: 0 PID: 1 at fs/sysfs/file.c:737 sysfs_emit (fs/sysfs/file.c:737)
> [ 17.141231][ T1] Modules linked in:
> [ 17.141878][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.15.0-rc5-00151-g0f807998661e #2
> [ 17.143180][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [ 17.144848][ T1] EIP: sysfs_emit (fs/sysfs/file.c:737)
> [ 17.145557][ T1] Code: e8 76 ec 66 00 83 c4 08 5b 5d c3 ba 01 00 00 00 b8 00 fa 50 cc e8 d1 a9 e2 ff 89 5c 24 04 c7 04 24 b1 88 c7 cb e8 da 0d 14 01 <0f> 0b b8 e8 f9 50 cc 31 c9 c7 04 24 01 00 00 00 ba 01 00 00 00 e8
> All code
> ========
> 0: e8 76 ec 66 00 callq 0x66ec7b
> 5: 83 c4 08 add $0x8,%esp
> 8: 5b pop %rbx
> 9: 5d pop %rbp
> a: c3 retq
> b: ba 01 00 00 00 mov $0x1,%edx
> 10: b8 00 fa 50 cc mov $0xcc50fa00,%eax
> 15: e8 d1 a9 e2 ff callq 0xffffffffffe2a9eb
> 1a: 89 5c 24 04 mov %ebx,0x4(%rsp)
> 1e: c7 04 24 b1 88 c7 cb movl $0xcbc788b1,(%rsp)
> 25: e8 da 0d 14 01 callq 0x1140e04
> 2a:* 0f 0b ud2 <-- trapping instruction
> 2c: b8 e8 f9 50 cc mov $0xcc50f9e8,%eax
> 31: 31 c9 xor %ecx,%ecx
> 33: c7 04 24 01 00 00 00 movl $0x1,(%rsp)
> 3a: ba 01 00 00 00 mov $0x1,%edx
> 3f: e8 .byte 0xe8
>
> Code starting with the faulting instruction
> ===========================================
> 0: 0f 0b ud2
> 2: b8 e8 f9 50 cc mov $0xcc50f9e8,%eax
> 7: 31 c9 xor %ecx,%ecx
> 9: c7 04 24 01 00 00 00 movl $0x1,(%rsp)
> 10: ba 01 00 00 00 mov $0x1,%edx
> 15: e8 .byte 0xe8
> [ 17.148128][ T1] EAX: 00000020 EBX: cce568e0 ECX: 00000000 EDX: 00000000
> [ 17.149078][ T1] ESI: cce54ae0 EDI: cce568e0 EBP: c181fed4 ESP: c181fec8
> [ 17.150009][ T1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010296
> [ 17.151159][ T1] CR0: 80050033 CR2: 00000000 CR3: 0c709000 CR4: 000406d0
> [ 17.152227][ T1] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
> [ 17.153237][ T1] DR6: fffe0ff0 DR7: 00000400
> [ 17.153964][ T1] Call Trace:
> [ 17.154511][ T1] btrfs_init_sysfs (fs/btrfs/sysfs.c:1310 fs/btrfs/sysfs.c:2023)
> [ 17.155279][ T1] ? tracefs_create_instance_dir (fs/btrfs/super.c:2552)
> [ 17.156161][ T1] init_btrfs_fs (fs/btrfs/super.c:2558)
> [ 17.156848][ T1] do_one_initcall (init/main.c:1303)
> [ 17.157551][ T1] ? parse_args (kernel/params.c:153 kernel/params.c:188)
> [ 17.158265][ T1] ? __this_cpu_preempt_check (lib/smp_processor_id.c:67)
> [ 17.159070][ T1] kernel_init_freeable (init/main.c:1375 init/main.c:1392 init/main.c:1411 init/main.c:1614)
> [ 17.163787][ T1] ? rest_init (init/main.c:1497)
> [ 17.171751][ T1] kernel_init (init/main.c:1507)
> [ 17.172549][ T1] ? schedule_tail_wrapper (arch/x86/entry/entry_32.S:740)
> [ 17.173320][ T1] ret_from_fork (arch/x86/entry/entry_32.S:775)
> [ 17.174042][ T1] irq event stamp: 2402249
> [ 17.174752][ T1] hardirqs last enabled at (2402257): __up_console_sem (kernel/printk/printk.c:255 (discriminator 1))
> [ 17.176070][ T1] hardirqs last disabled at (2402272): __up_console_sem (kernel/printk/printk.c:253 (discriminator 1))
> [ 17.177397][ T1] softirqs last enabled at (2402270): __do_softirq (kernel/softirq.c:402 kernel/softirq.c:587)
> [ 17.178704][ T1] softirqs last disabled at (2402265): do_softirq_own_stack (arch/x86/kernel/irq_32.c:60 arch/x86/kernel/irq_32.c:149)
> [ 17.180238][ T1] ---[ end trace c9e9be0944a14324 ]---
> [ 17.181055][ T1] ------------[ cut here ]------------
> [ 17.184298][ T1] invalid sysfs_emit: buf:cce568ed
>
>
> To reproduce:

A modload is good enough to reproduce. Unfortunately, I didn't check
the dmesg for Warnings during the hand testing.

Fixed in V2.

Thanks, Anand

>
> # build kernel
> cd linux
> cp config-5.15.0-rc5-00151-g0f807998661e .config
> make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 olddefconfig prepare modules_prepare bzImage
>
> 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
>
> # if come across any failure that blocks the test,
> # please remove ~/.lkp and /lkp dir to run from a clean state.
>
>
>
> ---
> 0DAY/LKP+ Test Infrastructure Open Source Technology Center
> https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation
>
> Thanks,
> Oliver Sang
>

2021-10-21 16:09:17

by David Sterba

[permalink] [raw]
Subject: Re: [btrfs] 0f80799866: WARNING:at_fs/sysfs/file.c:#sysfs_emit

On Thu, Oct 21, 2021 at 09:35:38PM +0800, kernel test robot wrote:
>
>
> Greeting,
>
> FYI, we noticed the following commit (built with gcc-9):
>
> commit: 0f807998661ecadb74638c18cbaff8785bb46f8d ("[PATCH 1/2] btrfs: sysfs convert scnprintf and snprintf to use sysfs_emit")
> url: https://github.com/0day-ci/linux/commits/Anand-Jain/provide-fsid-in-sysfs-devinfo/20211019-082356
> base: https://git.kernel.org/cgit/linux/kernel/git/kdave/linux.git for-next
>
> in testcase: boot
>
> on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G

I wonder if it's related to the 32bit host, I don't see any crash.

2021-10-21 16:24:09

by Anand Jain

[permalink] [raw]
Subject: Re: [btrfs] 0f80799866: WARNING:at_fs/sysfs/file.c:#sysfs_emit



On 22/10/2021 00:06, David Sterba wrote:
> On Thu, Oct 21, 2021 at 09:35:38PM +0800, kernel test robot wrote:
>>
>>
>> Greeting,
>>
>> FYI, we noticed the following commit (built with gcc-9):
>>
>> commit: 0f807998661ecadb74638c18cbaff8785bb46f8d ("[PATCH 1/2] btrfs: sysfs convert scnprintf and snprintf to use sysfs_emit")
>> url: https://github.com/0day-ci/linux/commits/Anand-Jain/provide-fsid-in-sysfs-devinfo/20211019-082356
>> base: https://git.kernel.org/cgit/linux/kernel/git/kdave/linux.git for-next
>>
>> in testcase: boot
>>
>> on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
>
> I wonder if it's related to the 32bit host, I don't see any crash.
>


We are hitting this warning:

int sysfs_emit(char *buf, const char *fmt, ...)
{
va_list args;
int len;

if (WARN(!buf || offset_in_page(buf), <====
"invalid sysfs_emit: buf:%p\n", buf))
return 0;
<snip>


The input buf wasn't page-aligned because it wasn't part of the show().