2023-03-14 08:38:00

by kernel test robot

[permalink] [raw]
Subject: [linux-stable-rc:linux-4.19.y] [panic] 4d00e68cfc: WARNING:at_fs/sysfs/file.c:#sysfs_emit_at

Greeting,

FYI, we noticed WARNING:at_fs/sysfs/file.c:#sysfs_emit_at due to commit (built with gcc-11):

commit: 4d00e68cfcfd91d3a8c794d47617429a96d623ed ("panic: Expose "warn_count" to sysfs")
https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable-rc.git linux-4.19.y

in testcase: trinity
version: trinity-static-x86_64-x86_64-1c734c75-1_2020-01-06
with following parameters:

runtime: 300s

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/

on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

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


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <[email protected]>
| Link: https://lore.kernel.org/oe-lkp/[email protected]


[ 91.396522] ------------[ cut here ]------------
[ 91.397797] invalid sysfs_emit_at: buf:000000004ba465f7 at:0
[ 91.399038] WARNING: CPU: 0 PID: 1032 at fs/sysfs/file.c:602 sysfs_emit_at (fs/sysfs/file.c:602 (discriminator 9))
[ 91.400702] Modules linked in: crc32c_intel aesni_intel aes_x86_64 pcspkr
[ 91.402049] CPU: 0 PID: 1032 Comm: trinity-c0 Not tainted 4.19.271-00075-g4d00e68cfcfd #1
[ 91.409221] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-5 04/01/2014
[ 91.411167] RIP: 0010:sysfs_emit_at (fs/sysfs/file.c:602 (discriminator 9))
[ 91.412300] Code: 31 c9 31 d2 44 89 fe 48 c7 c7 c8 21 3c 84 e8 2b cb d1 ff 45 85 ff 74 14 44 89 e2 48 89 de 48 c7 c7 a0 6a d8 82 e8 31 c5 14 01 <0f> 0b 31 c9 31 d2 44 89 fe 48 c7 c7 98 21 3c 84 e8 ff ca d1 ff 45
All code
========
0: 31 c9 xor %ecx,%ecx
2: 31 d2 xor %edx,%edx
4: 44 89 fe mov %r15d,%esi
7: 48 c7 c7 c8 21 3c 84 mov $0xffffffff843c21c8,%rdi
e: e8 2b cb d1 ff callq 0xffffffffffd1cb3e
13: 45 85 ff test %r15d,%r15d
16: 74 14 je 0x2c
18: 44 89 e2 mov %r12d,%edx
1b: 48 89 de mov %rbx,%rsi
1e: 48 c7 c7 a0 6a d8 82 mov $0xffffffff82d86aa0,%rdi
25: e8 31 c5 14 01 callq 0x114c55b
2a:* 0f 0b ud2 <-- trapping instruction
2c: 31 c9 xor %ecx,%ecx
2e: 31 d2 xor %edx,%edx
30: 44 89 fe mov %r15d,%esi
33: 48 c7 c7 98 21 3c 84 mov $0xffffffff843c2198,%rdi
3a: e8 ff ca d1 ff callq 0xffffffffffd1cb3e
3f: 45 rex.RB

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 31 c9 xor %ecx,%ecx
4: 31 d2 xor %edx,%edx
6: 44 89 fe mov %r15d,%esi
9: 48 c7 c7 98 21 3c 84 mov $0xffffffff843c2198,%rdi
10: e8 ff ca d1 ff callq 0xffffffffffd1cb14
15: 45 rex.RB
[ 91.415947] RSP: 0018:ffff88839cc1fa00 EFLAGS: 00010282
[ 91.416980] RAX: 0000000000000000 RBX: ffff88838b769168 RCX: 0000000000000000
[ 91.418321] RDX: 1ffff11071af5000 RSI: ffff88838d7a8888 RDI: ffffed1073983f36
[ 91.419751] RBP: ffff88839cc1fab8 R08: 0000000000000004 R09: 0000000000000000
[ 91.421196] R10: ffffffff81270059 R11: ffffffff84354eeb R12: 0000000000000000
[ 91.422617] R13: 1ffff11073983f40 R14: ffffffff82ca7140 R15: 0000000000000001
[ 91.424162] FS: 000000000109a880(0000) GS:ffffffff836bf000(0000) knlGS:0000000000000000
[ 91.425867] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 91.427062] CR2: 00007f4f623b2000 CR3: 00000003a8cba000 CR4: 00000000000406b0
[ 91.428458] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 91.429858] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 91.431301] Call Trace:
[ 91.431996] ? sysfs_emit (fs/sysfs/file.c:598)
[ 91.432848] ? lock_acquire (kernel/locking/lockdep.c:3910)
[ 91.433740] ? kernfs_seq_start (fs/kernfs/file.c:113)
[ 91.434689] ? __lock_is_held (kernel/locking/lockdep.c:3728)
[ 91.435558] ? klist_remove (lib/kobject.c:793)
[ 91.436437] pm_show_wakelocks (kernel/power/wakelock.c:53)
[ 91.437326] sysfs_kf_seq_show (fs/sysfs/file.c:63)
[ 91.438281] traverse (fs/seq_file.c:116)
[ 91.439109] seq_read (fs/seq_file.c:191 (discriminator 1))
[ 91.439949] do_loop_readv_writev (fs/read_write.c:704)
[ 91.440833] do_iter_read (fs/read_write.c:925)
[ 91.441616] vfs_readv (fs/read_write.c:988)
[ 91.442324] ? rw_copy_check_uvector (fs/read_write.c:979)
[ 91.443293] ? rcu_read_lock_sched_held (kernel/rcu/update.c:119)
[ 91.444338] do_preadv (fs/read_write.c:1071)
[ 91.445142] ? __x64_sys_readv (fs/read_write.c:1060)
[ 91.446045] ? do_syscall_64 (arch/x86/include/asm/paravirt.h:799 arch/x86/entry/common.c:280)
[ 91.446944] do_syscall_64 (arch/x86/entry/common.c:293)
[ 91.447774] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:244)
[ 91.448894] RIP: 0033:0x463519
[ 91.449627] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
All code
========
0: 00 f3 add %dh,%bl
2: c3 retq
3: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
a: 00 00 00
d: 0f 1f 40 00 nopl 0x0(%rax)
11: 48 89 f8 mov %rdi,%rax
14: 48 89 f7 mov %rsi,%rdi
17: 48 89 d6 mov %rdx,%rsi
1a: 48 89 ca mov %rcx,%rdx
1d: 4d 89 c2 mov %r8,%r10
20: 4d 89 c8 mov %r9,%r8
23: 4c 8b 4c 24 08 mov 0x8(%rsp),%r9
28: 0f 05 syscall
2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
30: 0f 83 db 59 00 00 jae 0x5a11
36: c3 retq
37: 66 data16
38: 2e cs
39: 0f .byte 0xf
3a: 1f (bad)
3b: 84 00 test %al,(%rax)
3d: 00 00 add %al,(%rax)
...

Code starting with the faulting instruction
===========================================
0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
6: 0f 83 db 59 00 00 jae 0x59e7
c: c3 retq
d: 66 data16
e: 2e cs
f: 0f .byte 0xf
10: 1f (bad)
11: 84 00 test %al,(%rax)
13: 00 00 add %al,(%rax)
...
[ 91.455329] RSP: 002b:00007ffffd5b9df8 EFLAGS: 00000246 ORIG_RAX: 0000000000000127
[ 91.456888] RAX: ffffffffffffffda RBX: 0000000000000127 RCX: 0000000000463519
[ 91.458335] RDX: 0000000000000001 RSI: 0000000001231800 RDI: 0000000000000078
[ 91.459796] RBP: 00007f4f623c8000 R08: 0000000000002000 R09: 00000000000000e9
[ 91.461235] R10: 0000000000100000 R11: 0000000000000246 R12: 0000000000000002
[ 91.462644] R13: 00007f4f623c8058 R14: 000000000109a850 R15: 00007f4f623c8000
[ 91.464065] irq event stamp: 274688
[ 91.464867] hardirqs last enabled at (274687): console_unlock (arch/x86/include/asm/paravirt.h:789 (discriminator 2) kernel/printk/printk.c:2498 (discriminator 2))
[ 91.466659] hardirqs last disabled at (274688): trace_hardirqs_off_thunk (arch/x86/entry/thunk_64.S:43)
[ 91.468608] softirqs last enabled at (274684): __do_softirq (arch/x86/include/asm/preempt.h:23 kernel/softirq.c:319)
[ 91.470384] softirqs last disabled at (274677): irq_exit (kernel/softirq.c:372 kernel/softirq.c:412)
[ 91.472049] ---[ end trace b63cb36c8c6dcdaa ]---


To reproduce:

# build kernel
cd linux
cp config-4.19.271-00075-g4d00e68cfcfd .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz 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.



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests


Attachments:
(No filename) (8.34 kB)
config-4.19.271-00075-g4d00e68cfcfd (117.40 kB)
job-script (4.35 kB)
dmesg.xz (26.89 kB)
trinity (2.80 kB)
Download all attachments

2023-03-17 06:32:20

by Eric Biggers

[permalink] [raw]
Subject: Re: [linux-stable-rc:linux-4.19.y] [panic] 4d00e68cfc: WARNING:at_fs/sysfs/file.c:#sysfs_emit_at

On Tue, Mar 14, 2023 at 04:34:22PM +0800, kernel test robot wrote:
> Greeting,
>
> FYI, we noticed WARNING:at_fs/sysfs/file.c:#sysfs_emit_at due to commit (built with gcc-11):
>
> commit: 4d00e68cfcfd91d3a8c794d47617429a96d623ed ("panic: Expose "warn_count" to sysfs")
> https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable-rc.git linux-4.19.y

It turns out this is a longstanding bug in 4.19.y and 4.14.y caused by a bad
backport, which is not actually related to the above commit (or the patch series
that contained it) at all. I've sent out fixes:

4.19: https://lore.kernel.org/r/[email protected]
4.14: https://lore.kernel.org/r/[email protected]

- Eric

2023-03-17 06:50:50

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [linux-stable-rc:linux-4.19.y] [panic] 4d00e68cfc: WARNING:at_fs/sysfs/file.c:#sysfs_emit_at

On Thu, Mar 16, 2023 at 11:32:13PM -0700, Eric Biggers wrote:
> On Tue, Mar 14, 2023 at 04:34:22PM +0800, kernel test robot wrote:
> > Greeting,
> >
> > FYI, we noticed WARNING:at_fs/sysfs/file.c:#sysfs_emit_at due to commit (built with gcc-11):
> >
> > commit: 4d00e68cfcfd91d3a8c794d47617429a96d623ed ("panic: Expose "warn_count" to sysfs")
> > https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable-rc.git linux-4.19.y
>
> It turns out this is a longstanding bug in 4.19.y and 4.14.y caused by a bad
> backport, which is not actually related to the above commit (or the patch series
> that contained it) at all. I've sent out fixes:
>
> 4.19: https://lore.kernel.org/r/[email protected]
> 4.14: https://lore.kernel.org/r/[email protected]

Thanks for these, I'll queue it up the next round.

greg k-h