[sched/core] f1a0a376ca: BUG:KASAN:stack-out-of-bounds_in_vsnprintf

From: kernel test robot
Date: Tue Jul 06 2021 - 10:52:08 EST

Next message: Geoff Levand: "Re: [PATCH] bus: Make remove callback return void"
Previous message: Pavel Skripkin: "[PATCH] media: em28xx: fix corrupted list"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Greeting,

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

commit: f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674 ("sched/core: Initialize the idle task with preemption disabled")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

in testcase: locktorture
version:
with following parameters:

runtime: 300s
test: cpuhotplug

test-description: This torture test consists of creating a number of kernel threads which acquire the lock and hold it for specific amount of time, thus simulating different critical region behaviors.
test-url: https://www.kernel.org/doc/Documentation/locking/locktorture.txt

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 <oliver.sang@xxxxxxxxx>

[ 227.905035] BUG: KASAN: stack-out-of-bounds in vsnprintf+0x1823/0x1a80
[ 227.905062] Read of size 8 at addr ffffc9000010ff00 by task swapper/1/0
[ 227.905084]
[ 227.905102] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.13.0-rc1-00108-gf1a0a376ca0c #1
[ 227.905133] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 227.905157] Call Trace:
[ 227.905171] dump_stack+0x198/0x247
[ 227.905190] print_address_description.cold+0x5/0x32d
[ 227.905212] ? vsnprintf+0x1823/0x1a80
[ 227.905229] kasan_report.cold+0x7c/0xd8
[ 227.905246] ? vsnprintf+0x1823/0x1a80
[ 227.905263] vsnprintf+0x1823/0x1a80
[ 227.905279] ? pointer+0x780/0x780
[ 227.905295] ? sched_clock_cpu+0x38/0x220
[ 227.905312] vprintk_store+0x14d/0xa80
[ 227.905330] ? __ia32_sys_syslog+0xc0/0xc0
[ 227.905348] ? ftrace_likely_update+0xa4/0x180
[ 227.905367] ? pvclock_clocksource_read+0x2dd/0x5a0
[ 227.905386] ? write_comp_data+0x2a/0x80
[ 227.905404] ? __sanitizer_cov_trace_pc+0x1d/0x60
[ 227.905423] vprintk_emit+0x144/0x600
[ 227.905439] vprintk+0xac/0x1e0
[ 227.905453] printk+0xa3/0xc1
[ 227.905470] ? stress_reorder_work.cold+0x2a/0x2a
[ 227.905489] ? slow_virt_to_phys+0x15b/0x340
[ 227.905507] ? ftrace_likely_update+0xa4/0x180
[ 227.905526] start_secondary+0x4a/0x280
[ 227.905544] secondary_startup_64_no_verify+0xb0/0xbb
[ 227.905561]
[ 227.905572]
[ 227.905592] addr ffffc9000010ff00 is located in stack of task swapper/1/0 at offset 120 in frame:
[ 227.905619] printk+0x0/0xc1
[ 227.905633]
[ 227.905646] this frame has 1 object:
[ 227.905664] [32, 56) 'args'
[ 227.905678]
[ 227.905694] Memory state around the buggy address:
[ 227.905718] ffffc9000010fe00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 227.905746] ffffc9000010fe80: 00 f1 f1 f1 f1 00 00 00 f3 f3 f3 f3 f3 00 00 00
[ 227.905775] >ffffc9000010ff00: f3 f3 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 227.905799] ^
[ 227.905820] ffffc9000010ff80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 227.905848] ffffc90000110000: f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8 f8
[ 227.905876] ==================================================================
[ 227.905902] Disabling lock debugging due to kernel taint
[ 227.974158] smpboot: CPU 1 is now offline
[ 231.067528] x86: Booting SMP configuration:
[ 231.068838] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 231.090360] kvm-clock: cpu 1, msr 8a01041, secondary cpu clock
[ 231.090509] masked ExtINT on CPU#1
[ 231.117328] kvm-guest: stealtime: cpu 1, msr 3aebf8080
[ 237.501337] smpboot: CPU 1 is now offline
[ 240.667721] x86: Booting SMP configuration:
[ 240.669915] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 240.672831] kvm-clock: cpu 1, msr 8a01041, secondary cpu clock
[ 240.672991] masked ExtINT on CPU#1
[ 240.713721] kvm-guest: stealtime: cpu 1, msr 3aebf8080

Kboot worker: lkp-worker51
Elapsed time: 240

kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-228.cgz
-m 16384
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)

append=(
ip=::::vm-snb-228::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-randconfig-a014-20210513
branch=tip/sched/core
commit=f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/vmlinuz-5.13.0-rc1-00108-gf1a0a376ca0c
vmalloc=512M
max_uptime=2100
RESULT_ROOT=/result/locktorture/300s-cpuhotplug/vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/21
result_service=tmpfs
selinux=0
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0

To reproduce:

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

---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@xxxxxxxxxxxx Intel Corporation

Thanks,
Oliver Sang

#!/bin/sh

export_top_env()
{
export suite='locktorture'
export testcase='locktorture'
export category='functional'
export need_modules=true
export need_memory='300MB'
export runtime=300
export job_origin='locktorture.yaml'
export queue_cmdline_keys=
export queue='int'
export testbox='vm-snb-228'
export tbox_group='vm-snb'
export branch='tip/sched/core'
export commit='f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674'
export kconfig='x86_64-randconfig-a014-20210513'
export nr_vm=160
export submit_id='60a47a900b9a9364a1ec58ed'
export job_file='/lkp/jobs/scheduled/vm-snb-228/locktorture-300s-cpuhotplug-debian-10.4-x86_64-20200603.cgz-f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674-20210519-25761-woq8s9-38.yaml'
export id='b977acb2f978482e90666402e67ebe95878195ca'
export queuer_version='/lkp/xsang/.src-20210519-100815'
export model='qemu-system-x86_64 -enable-kvm -cpu SandyBridge'
export nr_cpu=2
export memory='16G'
export need_kconfig='CONFIG_LOCK_TORTURE_TEST=m
CONFIG_SECURITY_LOADPIN_ENABLED=n ~ "<= v4.19"
CONFIG_SECURITY_LOADPIN_ENFORCE=n ~ ">= v4.20"
CONFIG_KVM_GUEST=y'
export ssh_base_port=23032
export kernel_cmdline='vmalloc=512M'
export rootfs='debian-10.4-x86_64-20200603.cgz'
export compiler='gcc-9'
export enqueue_time='2021-05-19 10:40:16 +0800'
export _id='60a47a920b9a9364a1ec5913'
export _rt='/result/locktorture/300s-cpuhotplug/vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674'
export user='lkp'
export LKP_SERVER='internal-lkp-server'
export result_root='/result/locktorture/300s-cpuhotplug/vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/21'
export scheduler_version='/lkp/lkp/src'
export arch='x86_64'
export max_uptime=2100
export initrd='/osimage/debian/debian-10.4-x86_64-20200603.cgz'
export bootloader_append='root=/dev/ram0
user=lkp
job=/lkp/jobs/scheduled/vm-snb-228/locktorture-300s-cpuhotplug-debian-10.4-x86_64-20200603.cgz-f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674-20210519-25761-woq8s9-38.yaml
ARCH=x86_64
kconfig=x86_64-randconfig-a014-20210513
branch=tip/sched/core
commit=f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/vmlinuz-5.13.0-rc1-00108-gf1a0a376ca0c
vmalloc=512M
max_uptime=2100
RESULT_ROOT=/result/locktorture/300s-cpuhotplug/vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/21
LKP_SERVER=internal-lkp-server
selinux=0
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
drbd.minor_count=8
systemd.log_level=err
ignore_loglevel
console=tty0
earlyprintk=ttyS0,115200
console=ttyS0,115200
vga=normal
rw'
export modules_initrd='/pkg/linux/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/modules.cgz'
export bm_initrd='/osimage/deps/debian-10.4-x86_64-20200603.cgz/run-ipconfig_20200608.cgz,/osimage/deps/debian-10.4-x86_64-20200603.cgz/lkp_20201211.cgz,/osimage/deps/debian-10.4-x86_64-20200603.cgz/rsync-rootfs_20200608.cgz'
export lkp_initrd='/osimage/user/lkp/lkp-x86_64.cgz'
export site='46a1f7098976'
export queue_at_least_once=1
export kernel='/pkg/linux/x86_64-randconfig-a014-20210513/gcc-9/f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674/vmlinuz-5.13.0-rc1-00108-gf1a0a376ca0c'
export dequeue_time='2021-05-19 10:53:29 +0800'
export job_initrd='/lkp/jobs/scheduled/vm-snb-228/locktorture-300s-cpuhotplug-debian-10.4-x86_64-20200603.cgz-f1a0a376ca0c4ef1fc3d24e3e502acbb5b795674-20210519-25761-woq8s9-38.cgz'

[ -n "$LKP_SRC" ] ||
export LKP_SRC=/lkp/${user:-lkp}/src
}

run_job()
{
echo $$ > $TMP/run-job.pid

. $LKP_SRC/lib/http.sh
. $LKP_SRC/lib/job.sh
. $LKP_SRC/lib/env.sh

export_top_env

run_monitor $LKP_SRC/monitors/wrapper kmsg
run_monitor $LKP_SRC/monitors/wrapper heartbeat
run_monitor $LKP_SRC/monitors/wrapper meminfo

run_test test='cpuhotplug' $LKP_SRC/tests/wrapper locktorture
}

extract_stats()
{
export stats_part_begin=
export stats_part_end=

env test='cpuhotplug' $LKP_SRC/stats/wrapper locktorture
$LKP_SRC/stats/wrapper kmsg
$LKP_SRC/stats/wrapper meminfo

$LKP_SRC/stats/wrapper time locktorture.time
$LKP_SRC/stats/wrapper dmesg
$LKP_SRC/stats/wrapper kmsg
$LKP_SRC/stats/wrapper last_state
$LKP_SRC/stats/wrapper stderr
$LKP_SRC/stats/wrapper time
}

"$@"

Attachment: dmesg.xz
Description: application/xz

Next message: Geoff Levand: "Re: [PATCH] bus: Make remove callback return void"
Previous message: Pavel Skripkin: "[PATCH] media: em28xx: fix corrupted list"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]