[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20151102121154.GB8833@wfg-t540p.sh.intel.com>
Date: Mon, 2 Nov 2015 20:11:54 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: Paolo Bonzini <pbonzini@...hat.com>
Cc: 0day robot <fengguang.wu@...el.com>, LKP <lkp@...org>,
LKML <linux-kernel@...r.kernel.org>
Subject: [x86/context_tracking] db23da8b95: inconsistent {IN-HARDIRQ-W} ->
{HARDIRQ-ON-W} usage.
Hi Paolo,
FYI, here is another bisect result.
https://github.com/0day-ci/linux Paolo-Bonzini/context_tracking-remove-duplicate-enabled-check/20151028-094317
commit db23da8b95ece9b57d4cfd63f5ee10502f1af0c8
Author: Paolo Bonzini <pbonzini@...hat.com>
AuthorDate: Wed Oct 28 02:39:57 2015 +0100
Commit: 0day robot <fengguang.wu@...el.com>
CommitDate: Wed Oct 28 09:43:20 2015 +0800
x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit
x86 always calls user_enter and user_exit with interrupt disabled.
Therefore, it is not necessary to check for exceptions, nor to
save/restore the IRQ state, when context tracking functions are
called by guest_enter and guest_exit.
Use the previously introduced __context_tracking_entry and
__context_tracking_exit.
Cc: Andy Lutomirski <luto@...nel.org>
Cc: Frederic Weisbecker <fweisbec@...il.com>
Cc: Rik van Riel <riel@...hat.com>
Cc: Paul McKenney <paulmck@...ux.vnet.ibm.com>
Signed-off-by: Paolo Bonzini <pbonzini@...hat.com>
+-------------------------------------------------+------------+------------+-----------------+
| | 66b6c205f3 | db23da8b95 | v4.3-rc7_102812 |
+-------------------------------------------------+------------+------------+-----------------+
| boot_successes | 63 | 0 | 0 |
| boot_failures | 0 | 23 | 24 |
| inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage | 0 | 23 | 24 |
| BUG:spinlock_lockup_suspected_on_CPU | 0 | 17 | 17 |
| RIP:native_write_msr_safe | 0 | 17 | 16 |
| RIP:delay_tsc | 0 | 2 | 3 |
| backtrace:native_smp_prepare_cpus | 0 | 11 | 16 |
| backtrace:kernel_init_freeable | 0 | 21 | 24 |
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0 | 4 | 1 |
| RIP:do_raw_spin_lock | 0 | 2 | 1 |
| RIP:native_safe_halt | 0 | 5 | 5 |
| backtrace:cpu_startup_entry | 0 | 4 | 3 |
| RIP:smp_call_function_single | 0 | 1 | 1 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0 | 1 | 6 |
| backtrace:bpf_prog_free_deferred | 0 | 1 | 1 |
| RIP:queued_spin_lock_slowpath | 0 | 1 | 3 |
| backtrace:apic_timer_interrupt | 0 | 10 | 2 |
| backtrace:driver_init | 0 | 10 | 2 |
| RIP:smp_call_function_many | 0 | 0 | 5 |
| backtrace:mutex_lock_nested | 0 | 0 | 1 |
| backtrace:init_workqueues | 0 | 0 | 1 |
+-------------------------------------------------+------------+------------+-----------------+
[ 6.931647] [ INFO: inconsistent lock state ]
[ 6.932033] 4.3.0-rc3-00098-gdb23da8 #1 Not tainted
[ 6.932464] ---------------------------------
[ 6.932860] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[ 6.933388] init/1 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 6.933827] (&(&(&p->vtime_seqlock)->lock)->rlock){?.-.-.}, at: [<ffffffff8af448ac>] vtime_account_user+0x2c/0x120
[ 6.934801] {IN-HARDIRQ-W} state was registered at:
[ 6.935233] [<ffffffff8af71a9b>] __lock_acquire+0x7ab/0x20a0
[ 6.935768] [<ffffffff8af73e47>] lock_acquire+0x137/0x2c0
[ 6.936277] [<ffffffff8b6fd1ed>] _raw_spin_lock+0x5d/0xe0
[ 6.936789] [<ffffffff8af4478c>] vtime_gen_account_irq_exit+0x2c/0x120
[ 6.937393] [<ffffffff8aef118c>] irq_exit+0x21c/0x240
[ 6.937874] [<ffffffff8b7011da>] smp_apic_timer_interrupt+0x7a/0x90
[ 6.938458] [<ffffffff8b6ffb1c>] apic_timer_interrupt+0x8c/0xa0
[ 6.939011] [<ffffffff8c429c7e>] driver_init+0x64/0x85
[ 6.939496] [<ffffffff8c3dd90c>] kernel_init_freeable+0xea/0x2c4
[ 6.940061] [<ffffffff8b6e9376>] kernel_init+0x16/0x190
[ 6.940554] [<ffffffff8b6ff11f>] ret_from_fork+0x3f/0x70
[ 6.941063] irq event stamp: 17784569
[ 6.941391] hardirqs last enabled at (17784569): [<ffffffff8b6ff8d5>] retint_user+0x18/0x20
[ 6.942152] hardirqs last disabled at (17784568): [<ffffffff8b700c3f>] error_exit+0xf/0x20
[ 6.942893] softirqs last enabled at (17784392): [<ffffffff8aef06a2>] __do_softirq+0x5c2/0x920
[ 6.943676] softirqs last disabled at (17784303): [<ffffffff8aef119e>] irq_exit+0x22e/0x240
[ 6.944426]
[ 6.944426] other info that might help us debug this:
[ 6.945009] Possible unsafe locking scenario:
[ 6.945009]
[ 6.945534] CPU0
[ 6.945763] ----
[ 6.945988] lock(&(&(&p->vtime_seqlock)->lock)->rlock);
[ 6.946495] <Interrupt>
[ 6.946738] lock(&(&(&p->vtime_seqlock)->lock)->rlock);
[ 6.947262]
[ 6.947262] *** DEADLOCK ***
[ 6.947262]
[ 6.947784] no locks held by init/1.
[ 6.948105]
[ 6.948105] stack backtrace:
[ 6.948487] CPU: 0 PID: 1 Comm: init Not tainted 4.3.0-rc3-00098-gdb23da8 #1
[ 6.949115] ffffffff8ccb1b80 ffff88000f4b7ca0 ffffffff8b222168 ffff88000f4b2000
[ 6.949825] ffff88000f4b7cf0 ffffffff8af70a9b 0000000000000000 0000000000000001
[ 6.950525] ffff880000000001 0000000000000002 ffff88000f4b2b48 0000000000000002
[ 6.951233] Call Trace:
[ 6.951462] [<ffffffff8b222168>] dump_stack+0x7c/0xb4
[ 6.951925] [<ffffffff8af70a9b>] print_usage_bug+0x2eb/0x300
[ 6.952433] [<ffffffff8af6fbb0>] ? print_irq_inversion_bug+0x3c0/0x3c0
[ 6.953014] [<ffffffff8af7102f>] mark_lock+0x57f/0x840
[ 6.953477] [<ffffffff8af71b3b>] __lock_acquire+0x84b/0x20a0
[ 6.953995] [<ffffffff8af71e33>] ? __lock_acquire+0xb43/0x20a0
[ 6.954521] [<ffffffff8ae6a78e>] ? pvclock_clocksource_read+0xae/0x1b0
[ 6.955107] [<ffffffff8af44a83>] ? vtime_user_enter+0xe3/0x100
[ 6.955633] [<ffffffff8af73e47>] lock_acquire+0x137/0x2c0
[ 6.956118] [<ffffffff8af448ac>] ? vtime_account_user+0x2c/0x120
[ 6.956664] [<ffffffff8b6fd1ed>] _raw_spin_lock+0x5d/0xe0
[ 6.957151] [<ffffffff8af448ac>] ? vtime_account_user+0x2c/0x120
[ 6.957695] [<ffffffff8af448ac>] vtime_account_user+0x2c/0x120
[ 6.958224] [<ffffffff8b06f02d>] __context_tracking_exit+0x8d/0x250
[ 6.958790] [<ffffffff8ae02a13>] enter_from_user_mode+0x133/0x1b0
[ 6.959338] [<ffffffff8ae02c27>] syscall_trace_enter_phase1+0x197/0x1d0
[ 6.959934] [<ffffffff8ae02017>] ? trace_hardirqs_on_thunk+0x17/0x19
[ 6.960503] [<ffffffff8b6fee35>] tracesys+0xd/0x44
[ 6.967454] mount (132) used greatest stack depth: 14272 bytes left
/etc/rcS.d/S00fbsetup: line 3: /sbin/modprobe: not found
[ 6.972548] S00fbsetup (134) used greatest stack depth: 14048 bytes left
git bisect start 4c68137ece9deccee9145554a186519a6efdb0e2 32b88194f71d6ae7768a29f87fbba454728273ee --
git bisect bad b5cc8fb80ac0bc043ae1f6aa4452ca31d1b02f71 # 19:30 0- 3 Merge 'linux-review/Masami-Hiramatsu/kselftests-ftrace-Add-event-trigger-testcases/20151022-192542' into devel-hourly-2015102812
git bisect bad 7b5c8e81803b1d416a855cfdb308df5aa0c499d9 # 19:39 0- 2 Merge 'iommu/x86/vt-d' into devel-hourly-2015102812
git bisect bad 348d2e673831351639247e0a7daed0ee6ca0a2e5 # 19:45 0- 1 Merge 'linux-review/Michael-S-Tsirkin/vhost-fix-performance-on-LE-hosts/20151027-174120' into devel-hourly-2015102812
git bisect good beaad0389cecdf2327d0c8c05df5ca307c294ea3 # 20:11 22+ 0 Merge 'linux-review/Hugh-Dickins/Re-PATCH-5-5-mm-mark-stable-page-dirty-in-KSM/20151027-102537' into devel-hourly-2015102812
git bisect bad 0cc2074395f14836ce070f57f989a9716927b104 # 20:19 0- 1 Merge 'kvms390/next' into devel-hourly-2015102812
git bisect good 890770b9d2817be118a19a41bde7e8569e9d6b27 # 20:27 22+ 0 Merge 'asoc/for-linus' into devel-hourly-2015102812
git bisect good c4483ea372d3139b312cb544d9b6e7e560ad661d # 20:35 22+ 0 Merge 'linux-review/Yaniv-Gardi/Fix-error-message-and-present-UFS-variant/20151025-185647' into devel-hourly-2015102812
git bisect bad 91a38360510069f988adcd0cb0a846f4b54cc272 # 20:42 0- 1 Merge 'kees/nak/proc-r' into devel-hourly-2015102812
git bisect good e35621a7144ff7d442edae15e991404249341ca3 # 20:51 20+ 0 Merge 'spi/topic/mtk' into devel-hourly-2015102812
git bisect bad b6c6953fa6e0a631bc38b44d5e49890a716ea3d2 # 21:09 0- 2 Merge 'linux-review/Paolo-Bonzini/context_tracking-remove-duplicate-enabled-check/20151028-094317' into devel-hourly-2015102812
git bisect good 87276880065246ce49ec571130d3d1e4a22e5604 # 21:18 22+ 0 KVM: x86: select IRQ_BYPASS_MANAGER
git bisect good 991e7a0eedf12721f5561d7a1a54d248dc290bc0 # 21:38 21+ 0 KVM: VMX: adjust interface to allocate/free_vpid
git bisect good 5225fdf8c8bea4418f69875804584c89a27c170e # 21:50 22+ 0 KVM: x86: MMU: Eliminate an extra memory slot search in mapping_level()
git bisect good f33143d80907602deb1b96db42da93507ed03b31 # 21:59 22+ 0 kvm/irqchip: allow only multiple irqchip routes per GSI
git bisect good 85ad248c62e8ab761dee8e785dc9cda7c0139688 # 22:12 22+ 0 context_tracking: remove duplicate enabled check
git bisect bad db23da8b95ece9b57d4cfd63f5ee10502f1af0c8 # 22:12 0- 23 x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit
git bisect good 66b6c205f3fd52a258b21b770ccd4b1e20fd6ed9 # 22:34 22+ 0 context_tracking: avoid irq_save/irq_restore on guest entry and exit
# first bad commit: [db23da8b95ece9b57d4cfd63f5ee10502f1af0c8] x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit
git bisect good 66b6c205f3fd52a258b21b770ccd4b1e20fd6ed9 # 22:37 63+ 0 context_tracking: avoid irq_save/irq_restore on guest entry and exit
# extra tests with DEBUG_INFO
git bisect bad db23da8b95ece9b57d4cfd63f5ee10502f1af0c8 # 22:45 0- 13 x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit
# extra tests on HEAD of linux-devel/devel-hourly-2015102812
git bisect bad 4c68137ece9deccee9145554a186519a6efdb0e2 # 22:45 0- 24 0day head guard for 'devel-hourly-2015102812'
# extra tests on tree/branch linux-review/Paolo-Bonzini/context_tracking-remove-duplicate-enabled-check/20151028-094317
git bisect bad db23da8b95ece9b57d4cfd63f5ee10502f1af0c8 # 22:46 0- 23 x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit
# extra tests with first bad commit reverted
git bisect good a7a0753125427d151178a88dc381a2d0acb15ce8 # 23:02 66+ 0 Revert "x86: context_tracking: avoid irq_save/irq_restore on kernel entry and exit"
# extra tests on tree/branch linus/master
git bisect good 38dab9ac1c017e96dc98e978111e365134d41d13 # 23:11 61+ 0 Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/dtor/input
# extra tests on tree/branch linux-next/master
git bisect good 6dcf94ff0c9e28e5790799e53641dd256745f425 # 23:23 66+ 0 Add linux-next specific files for 20151022
This script may reproduce the error.
----------------------------------------------------------------------------
#!/bin/bash
kernel=$1
initrd=yocto-minimal-x86_64.cgz
wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu Haswell,+smep,+smap
-kernel $kernel
-initrd $initrd
-m 256
-smp 1
-device e1000,netdev=net0
-netdev user,id=net0
-boot order=nc
-no-reboot
-watchdog i6300esb
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
hung_task_panic=1
earlyprintk=ttyS0,115200
systemd.log_level=err
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
console=ttyS0,115200
console=tty0
vga=normal
root=/dev/ram0
rw
drbd.minor_count=8
)
"${kvm[@]}" --append "${append[*]}"
----------------------------------------------------------------------------
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
View attachment "dmesg-yocto-ivb42-62:20151031214229:x86_64-randconfig-n0-10311847:4.3.0-rc3-00098-gdb23da8:1" of type "text/plain" (89048 bytes)
View attachment "config-4.3.0-rc3-00098-gdb23da8" of type "text/plain" (87516 bytes)
Powered by blists - more mailing lists