[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20170611025234.GA40741@inn.lkp.intel.com>
Date: Sun, 11 Jun 2017 10:52:34 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Andy Lutomirski <luto@...nel.org>
Cc: LKML <linux-kernel@...r.kernel.org>,
Andy Lutomirski <luto@...capital.net>, lkp@...org
Subject: [x86/mm] a9f26cff1a: kernel_BUG_at_arch/x86/mm/tlb.c
FYI, we noticed the following commit:
commit: a9f26cff1a956abad8a611216a01400019f5185f ("x86/mm: Try to preserve old TLB entries using PCID")
https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git x86/pcid
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------+------------+------------+
| | a1d3da72bb | a9f26cff1a |
+-------------------------------------------------+------------+------------+
| boot_successes | 14 | 14 |
| boot_failures | 1 | 35 |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | |
| kernel_BUG_at_arch/x86/mm/tlb.c | 0 | 35 |
| invalid_opcode:#[##] | 0 | 35 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 34 |
+-------------------------------------------------+------------+------------+
[ 180.416105] kernel BUG at arch/x86/mm/tlb.c:119!
[ 180.432687] invalid opcode: 0000 [#1] SMP
[ 180.444001] Modules linked in: snd_pcsp
[ 180.455933] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.12.0-rc4-00024-ga9f26cf #31
[ 180.478834] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 180.512086] task: ffffffffac428500 task.stack: ffffffffac400000
[ 180.530755] RIP: 0010:switch_mm_irqs_off+0x5c/0x5ab
[ 180.547761] RSP: 0018:ffffffffac403da0 EFLAGS: 00010093
[ 180.564556] RAX: 00000001124c9003 RBX: ffff8d5651994d40 RCX: 0000000000000028
[ 180.583966] RDX: 0000000000000003 RSI: ffff8d5651994d40 RDI: ffff8d56d24c9000
[ 180.605062] RBP: ffffffffac403dc8 R08: 0000000000000000 R09: 0000002a007e0000
[ 180.622815] R10: 0000000000000001 R11: 0000000000000005 R12: 0000000000000000
[ 180.642552] R13: ffff8d5651994d40 R14: ffff8d5651990003 R15: 00000001124c9000
[ 180.661933] FS: 0000000000000000(0000) GS:ffff8d567b200000(0000) knlGS:0000000000000000
[ 180.685321] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 180.702818] CR2: 00005573cc330c38 CR3: 00000001124c9000 CR4: 00000000000206f0
[ 180.724086] Call Trace:
[ 180.734942] __schedule+0x873/0xa74
[ 180.745628] ? tick_nohz_idle_exit+0xd0/0xdc
[ 180.757554] schedule_idle+0x2e/0x38
[ 180.770550] do_idle+0x18a/0x195
[ 180.782993] cpu_startup_entry+0x1f/0x21
[ 180.796740] rest_init+0x135/0x13b
[ 180.809506] start_kernel+0x3f5/0x402
[ 180.822596] ? early_idt_handler_array+0x120/0x120
[ 180.837598] x86_64_start_reservations+0x29/0x2b
[ 180.850526] x86_64_start_kernel+0x140/0x14f
[ 180.864337] secondary_startup_64+0x9f/0x9f
[ 180.879657] Code: 66 90 66 90 0f ba e0 09 73 02 0f ff 0f 20 d8 66 66 66 90 49 8b 7d 50 49 89 c7 e8 0d f0 ff ff 41 0f b7 d6 48 09 d0 49 39 c7 74 02 <0f> 0b 49 8d 8d a8 03 00 00 49 39 dd 44 89 e0 0f 85 3f 01 00 00
[ 180.935527] RIP: switch_mm_irqs_off+0x5c/0x5ab RSP: ffffffffac403da0
[ 180.953313]
[ 180.953315] ======================================================
[ 180.953317] WARNING: possible circular locking dependency detected
[ 180.953318] 4.12.0-rc4-00024-ga9f26cf #31 Not tainted
[ 180.953320] ------------------------------------------------------
[ 180.953321] swapper/0/0 is trying to acquire lock:
[ 180.953322] ((console_sem).lock){-.-...}, at: [<ffffffffab0e4cd5>] down_trylock+0x14/0x37
[ 180.953347]
[ 180.953348] but task is already holding lock:
[ 180.953349] (&rq->lock){-.-.-.}, at: [<ffffffffabd4f1af>] __schedule+0x1c7/0xa74
[ 180.953353]
[ 180.953355] which lock already depends on the new lock.
[ 180.953355]
[ 180.953377]
[ 180.953378] the existing dependency chain (in reverse order) is:
[ 180.953379]
[ 180.953380] -> #2 (&rq->lock){-.-.-.}:
[ 180.953384] __lock_acquire+0xd44/0xe43
[ 180.953385] lock_acquire+0x142/0x1dd
[ 180.953386] _raw_spin_lock+0x34/0x6a
[ 180.953388] task_fork_fair+0x32/0x13e
[ 180.953409] sched_fork+0x163/0x1e1
[ 180.953411] copy_process+0x7e2/0x1c10
[ 180.953412] _do_fork+0xbb/0x60c
[ 180.953413] kernel_thread+0x29/0x2b
[ 180.953414] rest_init+0x22/0x13b
[ 180.953415] start_kernel+0x3f5/0x402
[ 180.953416] x86_64_start_reservations+0x29/0x2b
[ 180.953418] x86_64_start_kernel+0x140/0x14f
[ 180.953419] verify_cpu+0x0/0xf1
[ 180.953419]
[ 180.953420] -> #1 (&p->pi_lock){-.-.-.}:
[ 180.953447] __lock_acquire+0xd44/0xe43
[ 180.953449] lock_acquire+0x142/0x1dd
[ 180.953451] _raw_spin_lock_irqsave+0x4d/0x88
[ 180.953452] try_to_wake_up+0x35/0x575
[ 180.953475] wake_up_process+0x15/0x17
[ 180.953476] __up+0x4c/0x4f
[ 180.953478] up+0x32/0x42
[ 180.953479] __up_console_sem+0x45/0x73
[ 180.953481] console_unlock+0x30f/0x4d6
[ 180.953482] vprintk_emit+0x26d/0x2c2
[ 180.953484] vprintk_default+0x1d/0x1f
[ 180.953507] vprintk_func+0x4a/0x4c
[ 180.953510] printk+0x43/0x4b
[ 180.953511] rcu_torture_stats_print+0x19e/0x425
[ 180.953513] rcu_torture_stats+0x4b/0x6d
[ 180.953515] kthread+0x134/0x13c
[ 180.953517] ret_from_fork+0x2a/0x40
[ 180.953538]
[ 180.953540] -> #0 ((console_sem).lock){-.-...}:
[ 180.953546] check_prevs_add+0x18c/0x5fd
[ 180.953548] __lock_acquire+0xd44/0xe43
[ 180.953549] lock_acquire+0x142/0x1dd
[ 180.953572] _raw_spin_lock_irqsave+0x4d/0x88
[ 180.953573] down_trylock+0x14/0x37
[ 180.953575] __down_trylock_console_sem+0x38/0xa2
[ 180.953577] console_trylock+0x13/0x77
[ 180.953579] vprintk_emit+0x264/0x2c2
[ 180.953580] vprintk_default+0x1d/0x1f
[ 180.953582] vprintk_func+0x4a/0x4c
[ 180.953604] printk+0x43/0x4b
[ 180.953606] report_bug+0x93/0xc8
[ 180.953607] do_trap+0x63/0x147
[ 180.953609] do_error_trap+0x10b/0x11a
[ 180.953611] do_invalid_op+0x20/0x22
[ 180.953612] invalid_op+0x1e/0x30
[ 180.953614] switch_mm_irqs_off+0x5c/0x5ab
[ 180.953636] __schedule+0x873/0xa74
[ 180.953638] schedule_idle+0x2e/0x38
[ 180.953640] do_idle+0x18a/0x195
[ 180.953641] cpu_startup_entry+0x1f/0x21
[ 180.953643] rest_init+0x135/0x13b
[ 180.953645] start_kernel+0x3f5/0x402
[ 180.953647] x86_64_start_reservations+0x29/0x2b
[ 180.953669] x86_64_start_kernel+0x140/0x14f
[ 180.953671] verify_cpu+0x0/0xf1
[ 180.953672]
[ 180.953674] other info that might help us debug this:
[ 180.953675]
[ 180.953677] Chain exists of:
[ 180.953678] (console_sem).lock --> &p->pi_lock --> &rq->lock
[ 180.953707]
[ 180.953709] Possible unsafe locking scenario:
[ 180.953710]
[ 180.953711] CPU0 CPU1
[ 180.953734] ---- ----
[ 180.953735] lock(&rq->lock);
[ 180.953739] lock(&p->pi_lock);
[ 180.953744] lock(&rq->lock);
[ 180.953769] lock((console_sem).lock);
[ 180.953772]
[ 180.953774] *** DEADLOCK ***
[ 180.953775]
[ 180.953777] 1 lock held by swapper/0/0:
[ 180.953798] #0: (&rq->lock){-.-.-.}, at: [<ffffffffabd4f1af>] __schedule+0x1c7/0xa74
[ 180.953805]
[ 180.953807] stack backtrace:
[ 180.953809] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.12.0-rc4-00024-ga9f26cf #31
[ 180.953833] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 180.953835] Call Trace:
[ 180.953836] dump_stack+0x86/0xc0
[ 180.953838] print_circular_bug+0x272/0x280
To reproduce:
git clone https://github.com/01org/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Kernel Test Robot
View attachment "config-4.12.0-rc4-00024-ga9f26cf" of type "text/plain" (117074 bytes)
View attachment "job-script" of type "text/plain" (4236 bytes)
Download attachment "dmesg.xz" of type "application/octet-stream" (17108 bytes)
Powered by blists - more mailing lists