lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<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

Powered by Openwall GNU/*/Linux Powered by OpenVZ