[Bug 105600] [CI] igt@* - incomplete - Softdog on first test on gvtvm machines, lockdep in boot.log
bugzilla-daemon at freedesktop.org
bugzilla-daemon at freedesktop.org
Tue Mar 20 06:49:38 UTC 2018
https://bugs.freedesktop.org/show_bug.cgi?id=105600
Marta Löfstedt <marta.lofstedt at intel.com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Summary|[CI] |[CI] igt@* - incomplete -
|igt at kms_frontbuffer_trackin |Softdog on first test on
|g at fbcdrrs-1p-primscrn-cur-i |gvtvm machines, lockdep in
|ndfb-draw-* - incomplete - |boot.log
|Softdog |
--- Comment #6 from Marta Löfstedt <marta.lofstedt at intel.com> ---
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_4/fi-bdw-gvtdvm/igt@kms_properties@plane-properties-atomic.html
run.log:
running: igt/kms_properties/plane-properties-atomic
[00/97] |
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
Full dmesg:
<5>[ 24.071216] owatch: Using watchdog device /dev/watchdog0
<5>[ 24.073518] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 24.076762] owatch: timeout for /dev/watchdog0 set to 410 (requested 410)
<6>[ 25.127388] perf: interrupt took too long (3211 > 3197), lowering
kernel.perf_event_max_sample_rate to 62000
<6>[ 30.692676] perf: interrupt took too long (4124 > 4013), lowering
kernel.perf_event_max_sample_rate to 48000
<7>[ 31.118853] [IGT] kms_properties: executing
boot log:
<4>[ 10.874799] ------------[ cut here ]------------
<3>[ 10.875470] ODEBUG: free active (active state 0) object type: hrtimer
hint: hrtimer_wakeup+0x0/0x20
<4>[ 10.876334] WARNING: CPU: 0 PID: 196 at lib/debugobjects.c:291
debug_print_object+0x67/0x80
<4>[ 10.877186] Modules linked in: i915(+) crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel prime_numbers e1000(+) i2c_piix4
<4>[ 10.878107] CPU: 0 PID: 196 Comm: systemd-udevd Not tainted
4.16.0-rc5-g639c78d2805b-drmtip_4+ #1
<4>[ 10.878977] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
<4>[ 10.879886] RIP: 0010:debug_print_object+0x67/0x80
<4>[ 10.880345] RSP: 0018:ffffa5c0c027fcd8 EFLAGS: 00010092
<4>[ 10.880895] RAX: 0000000000000057 RBX: ffffa24c27a8dbf0 RCX:
0000000000000002
<4>[ 10.881399] RDX: 0000000080000002 RSI: ffffffffa8076546 RDI:
00000000ffffffff
<4>[ 10.881948] RBP: ffffffffa8249cc0 R08: 0000000000000000 R09:
0000000000000000
<4>[ 10.882452] R10: ffffa5c0c027fc70 R11: ffffffffa70efb8b R12:
ffffffffa80747d4
<4>[ 10.883022] R13: ffffffffa97b9560 R14: 0000000000000001 R15:
ffffffffa97b9568
<4>[ 10.883528] FS: 00007f5f6abb8480(0000) GS:ffffa24c3fc00000(0000)
knlGS:0000000000000000
<4>[ 10.884392] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 10.884912] CR2: 00005572006db178 CR3: 00000000780c0006 CR4:
00000000003606f0
<4>[ 10.885417] Call Trace:
<4>[ 10.885895] debug_check_no_obj_freed+0x1ef/0x230
<4>[ 10.886364] __vunmap+0x5b/0x110
<4>[ 10.886797] load_module+0x2347/0x2dc0
<4>[ 10.887261] ? show_coresize+0x20/0x20
<4>[ 10.887701] ? vfs_read+0x126/0x150
<4>[ 10.888179] ? SyS_finit_module+0xa5/0xe0
<4>[ 10.888631] SyS_finit_module+0xa5/0xe0
<4>[ 10.889117] do_syscall_64+0x65/0x1a0
<4>[ 10.889557] entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[ 10.890065] RIP: 0033:0x7f5f6a4bc839
<4>[ 10.890501] RSP: 002b:00007fff477482b8 EFLAGS: 00000246 ORIG_RAX:
0000000000000139
<4>[ 10.891346] RAX: ffffffffffffffda RBX: 00005640e00d8730 RCX:
00007f5f6a4bc839
<4>[ 10.891851] RDX: 0000000000000000 RSI: 00007f5f6a19b0e5 RDI:
000000000000000f
<4>[ 10.892402] RBP: 00007f5f6a19b0e5 R08: 0000000000000000 R09:
00007fff477483d0
<4>[ 10.892907] R10: 000000000000000f R11: 0000000000000246 R12:
0000000000000000
<4>[ 10.893452] R13: 00005640e00cdd30 R14: 0000000000020000 R15:
00005640e00d8730
<4>[ 10.893959] Code: c1 8b 43 10 83 c2 01 8b 4b 14 89 15 2c b5 28 02 4c 8b
45 00 4c 89 e6 48 c7 c7 30 83 09 a8 48 8b 14 c5 e0 3b e4 a7 e8 09 f3 c1 ff <0f>
0b 5b 83 05 2b 48 ee 00 01 5d 41 5c c3 83 05 20 48 ee 00 01
<4>[ 10.895420] WARNING: CPU: 0 PID: 196 at lib/debugobjects.c:291
debug_print_object+0x67/0x80
<4>[ 10.896303] ---[ end trace 77cae12efc453097 ]---
<4>[ 10.896773] ======================================================
<4>[ 10.896773] WARNING: possible circular locking dependency detected
<4>[ 10.896773] 4.16.0-rc5-g639c78d2805b-drmtip_4+ #1 Not tainted
<4>[ 10.896774] ------------------------------------------------------
<4>[ 10.896774] systemd-udevd/196 is trying to acquire lock:
<4>[ 10.896774] ((console_sem).lock){..-.}, at: [<00000000673d59fd>]
down_trylock+0xa/0x30
<4>[ 10.896776] but task is already holding lock:
<4>[ 10.896776] (&obj_hash[i].lock){-.-.}, at: [<000000002f519ca4>]
debug_check_no_obj_freed+0xa4/0x230
<4>[ 10.896777] which lock already depends on the new lock.
<4>[ 10.896778] the existing dependency chain (in reverse order) is:
<4>[ 10.896779] -> #3 (&obj_hash[i].lock){-.-.}:
<4>[ 10.896780] __debug_object_init+0x5f/0x430
<4>[ 10.896780] hrtimer_init+0x1b/0x150
<4>[ 10.896780] init_dl_task_timer+0x17/0x30
<4>[ 10.896781] __sched_fork.isra.16+0xa7/0x100
<4>[ 10.896781] init_idle+0x53/0x270
<4>[ 10.896781] sched_init+0x42f/0x4a5
<4>[ 10.896782] start_kernel+0x20e/0x3f0
<4>[ 10.896782] secondary_startup_64+0xa5/0xb0
<4>[ 10.896782] -> #2 (&rq->lock){-.-.}:
<4>[ 10.896783] task_fork_fair+0x36/0x120
<4>[ 10.896784] sched_fork+0x12f/0x2a0
<4>[ 10.896784] copy_process.part.7+0x5e4/0x1d90
<4>[ 10.896784] _do_fork+0xc0/0x6b0
<4>[ 10.896785] kernel_thread+0x20/0x30
<4>[ 10.896785] rest_init+0x1d/0x220
<4>[ 10.896785] start_kernel+0x3e8/0x3f0
<4>[ 10.896786] secondary_startup_64+0xa5/0xb0
<4>[ 10.896786] -> #1 (&p->pi_lock){-.-.}:
<4>[ 10.896787] try_to_wake_up+0x27/0x610
<4>[ 10.896787] up+0x3b/0x50
<4>[ 10.896788] __up_console_sem+0x2e/0x50
<4>[ 10.896788] console_unlock+0x31f/0x650
<4>[ 10.896788] con_write+0x43/0x60
<4>[ 10.896789] n_tty_write+0x1a7/0x450
<4>[ 10.896789] tty_write+0x1b6/0x2e0
<4>[ 10.896789] do_iter_write+0x140/0x180
<4>[ 10.896790] vfs_writev+0x84/0xf0
<4>[ 10.896790] do_writev+0x4c/0xd0
<4>[ 10.896790] do_syscall_64+0x65/0x1a0
<4>[ 10.896790] entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[ 10.896791] -> #0 ((console_sem).lock){..-.}:
<4>[ 10.896792] _raw_spin_lock_irqsave+0x33/0x50
<4>[ 10.896792] down_trylock+0xa/0x30
<4>[ 10.896793] __down_trylock_console_sem+0x20/0x80
<4>[ 10.896793] console_trylock+0xe/0x60
<4>[ 10.896793] vprintk_emit+0x24f/0x4f0
<4>[ 10.896793] printk+0x3e/0x46
<4>[ 10.896794] __warn_printk+0x37/0x70
<4>[ 10.896794] debug_print_object+0x67/0x80
<4>[ 10.896794] debug_check_no_obj_freed+0x1ef/0x230
<4>[ 10.896795] __vunmap+0x5b/0x110
<4>[ 10.896795] load_module+0x2347/0x2dc0
<4>[ 10.896795] SyS_finit_module+0xa5/0xe0
<4>[ 10.896795] do_syscall_64+0x65/0x1a0
<4>[ 10.896796] entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[ 10.896796] other info that might help us debug this:
<4>[ 10.896797] Chain exists of:
<4>[ 10.896797] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock
<4>[ 10.896799] Possible unsafe locking scenario:
<4>[ 10.896799] CPU0 CPU1
<4>[ 10.896800] ---- ----
<4>[ 10.896800] lock(&obj_hash[i].lock);
<4>[ 10.896801] lock(&rq->lock);
<4>[ 10.896801] lock(&obj_hash[i].lock);
<4>[ 10.896802] lock((console_sem).lock);
<4>[ 10.896803] *** DEADLOCK ***
<4>[ 10.896803] 1 lock held by systemd-udevd/196:
<4>[ 10.896804] #0: (&obj_hash[i].lock){-.-.}, at: [<000000002f519ca4>]
debug_check_no_obj_freed+0xa4/0x230
<4>[ 10.896805] stack backtrace:
<4>[ 10.896805] CPU: 0 PID: 196 Comm: systemd-udevd Not tainted
4.16.0-rc5-g639c78d2805b-drmtip_4+ #1
<4>[ 10.896806] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
<4>[ 10.896806] Call Trace:
<4>[ 10.896807] dump_stack+0x5f/0x86
<4>[ 10.896807] print_circular_bug.isra.18+0x1d0/0x2c0
<4>[ 10.896807] __lock_acquire+0x14ae/0x1b60
<4>[ 10.896807] ? lock_acquire+0xaf/0x200
<4>[ 10.896808] lock_acquire+0xaf/0x200
<4>[ 10.896808] ? down_trylock+0xa/0x30
<4>[ 10.896808] ? vprintk_emit+0x24f/0x4f0
<4>[ 10.896809] _raw_spin_lock_irqsave+0x33/0x50
<4>[ 10.896809] ? down_trylock+0xa/0x30
<4>[ 10.896809] down_trylock+0xa/0x30
<4>[ 10.896809] __down_trylock_console_sem+0x20/0x80
<4>[ 10.896810] console_trylock+0xe/0x60
<4>[ 10.896810] vprintk_emit+0x24f/0x4f0
<4>[ 10.896810] printk+0x3e/0x46
<4>[ 10.896811] ? clock_was_set_work+0x20/0x20
<4>[ 10.896811] __warn_printk+0x37/0x70
<4>[ 10.896811] ? debug_check_no_obj_freed+0xa4/0x230
<4>[ 10.896811] ? clock_was_set_work+0x20/0x20
<4>[ 10.896812] debug_print_object+0x67/0x80
<4>[ 10.896812] debug_check_no_obj_freed+0x1ef/0x230
<4>[ 10.896812] __vunmap+0x5b/0x110
<4>[ 10.896813] load_module+0x2347/0x2dc0
<4>[ 10.896813] ? show_coresize+0x20/0x20
<4>[ 10.896813] ? vfs_read+0x126/0x150
<4>[ 10.896813] ? SyS_finit_module+0xa5/0xe0
<4>[ 10.896814] SyS_finit_module+0xa5/0xe0
<4>[ 10.896814] do_syscall_64+0x65/0x1a0
<4>[ 10.896814] entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[ 10.896815] RIP: 0033:0x7f5f6a4bc839
<4>[ 10.896815] RSP: 002b:00007fff477482b8 EFLAGS: 00000246 ORIG_RAX:
0000000000000139
<4>[ 10.896816] RAX: ffffffffffffffda RBX: 00005640e00d8730 RCX:
00007f5f6a4bc839
<4>[ 10.896816] RDX: 0000000000000000 RSI: 00007f5f6a19b0e5 RDI:
000000000000000f
<4>[ 10.896816] RBP: 00007f5f6a19b0e5 R08: 0000000000000000 R09:
00007fff477483d0
<4>[ 10.896817] R10: 000000000000000f R11: 0000000000000246 R12:
0000000000000000
<4>[ 10.896817] R13: 00005640e00cdd30 R14: 0000000000020000 R15:
00005640e00d8730
<1>[ 12.520047] BUG: unable to handle kernel NULL pointer dereference at
0000000000000010
<1>[ 12.520325] IP: hrtimer_active+0x4/0x40
<6>[ 12.520485] PGD 0 P4D 0
<4>[ 12.520613] Oops: 0000 [#1] PREEMPT SMP PTI
<4>[ 12.520772] Modules linked in: i915(+) crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel prime_numbers e1000(+) i2c_piix4
<4>[ 12.521105] CPU: 0 PID: 196 Comm: systemd-udevd Tainted: G W
4.16.0-rc5-g639c78d2805b-drmtip_4+ #1
<4>[ 12.521391] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
<4>[ 12.521699] RIP: 0010:hrtimer_active+0x4/0x40
<4>[ 12.521860] RSP: 0018:ffffa5c0c027fca8 EFLAGS: 00010282
<4>[ 12.522038] RAX: 0000000000000000 RBX: ffffa5c0c0343a18 RCX:
0000000000000001
<4>[ 12.522276] RDX: 0000000000000003 RSI: 0000000000000003 RDI:
ffffa5c0c0343a18
<4>[ 12.522490] RBP: 0000000000000000 R08: ffffa5c0c0343a18 R09:
0000000000000000
<4>[ 12.522705] R10: 0000000000000000 R11: ffffffffa70efb8b R12:
ffffa5c0c548f000
<4>[ 12.522920] R13: ffffffffa97b9560 R14: ffffffffa8249cc0 R15:
ffffffffa97b9568
<4>[ 12.523166] FS: 00007f5f6abb8480(0000) GS:ffffa24c3fc00000(0000)
knlGS:0000000000000000
<4>[ 12.523412] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 12.523601] CR2: 0000000000000010 CR3: 00000000780c0005 CR4:
00000000003606f0
<4>[ 12.524112] Call Trace:
<4>[ 12.524563] hrtimer_try_to_cancel+0x14/0x1d0
<4>[ 12.525016] hrtimer_fixup_free+0x15/0x40
<4>[ 12.525505] debug_object_fixup+0xf/0x30
<4>[ 12.525948] debug_check_no_obj_freed+0x221/0x230
<4>[ 12.526451] __vunmap+0x5b/0x110
<4>[ 12.526893] load_module+0x2347/0x2dc0
<4>[ 12.527399] ? show_coresize+0x20/0x20
<4>[ 12.527844] ? vfs_read+0x126/0x150
<4>[ 12.528285] ? SyS_finit_module+0xa5/0xe0
<4>[ 12.528760] SyS_finit_module+0xa5/0xe0
<4>[ 12.529204] do_syscall_64+0x65/0x1a0
<4>[ 12.529685] entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[ 12.530151] RIP: 0033:0x7f5f6a4bc839
<4>[ 12.530628] RSP: 002b:00007fff477482b8 EFLAGS: 00000246 ORIG_RAX:
0000000000000139
<4>[ 12.531433] RAX: ffffffffffffffda RBX: 00005640e00d8730 RCX:
00007f5f6a4bc839
<4>[ 12.531976] RDX: 0000000000000000 RSI: 00007f5f6a19b0e5 RDI:
000000000000000f
<4>[ 12.532487] RBP: 00007f5f6a19b0e5 R08: 0000000000000000 R09:
00007fff477483d0
<4>[ 12.533031] R10: 000000000000000f R11: 0000000000000246 R12:
0000000000000000
<4>[ 12.533550] R13: 00005640e00cdd30 R14: 0000000000020000 R15:
00005640e00d8730
<4>[ 12.534085] Code: ff ff ff 48 8b 57 70 eb bf 0f 1f 40 00 66 2e 0f 1f 84
00 00 00 00 00 48 c7 47 28 10 b5 10 a7 48 89 77 40 c3 0f 1f 00 48 8b 47 30 <8b>
50 10 f6 c2 01 75 1d 80 7f 38 00 75 23 48 3b 78 38 74 1d 39
<1>[ 12.535484] RIP: hrtimer_active+0x4/0x40 RSP: ffffa5c0c027fca8
<4>[ 12.536008] CR2: 0000000000000010
<4>[ 12.536447] ---[ end trace 77cae12efc453098 ]---
<3>[ 12.536945] BUG: sleeping function called from invalid context at
./include/linux/percpu-rwsem.h:34
<3>[ 12.537821] in_atomic(): 0, irqs_disabled(): 1, pid: 196, name:
systemd-udevd
<4>[ 12.538327] INFO: lockdep is turned off.
<4>[ 12.538771] irq event stamp: 365170
<4>[ 12.539247] hardirqs last enabled at (365169): [<0000000025e2fc5e>]
_raw_spin_unlock_irqrestore+0x4c/0x60
<4>[ 12.540135] hardirqs last disabled at (365170): [<0000000037f8c343>]
_raw_spin_lock_irqsave+0xd/0x50
<4>[ 12.541021] softirqs last enabled at (360940): [<0000000020eb4dde>]
__do_softirq+0x3a1/0x4aa
<4>[ 12.541847] softirqs last disabled at (360933): [<000000004c971658>]
irq_exit+0xa4/0xb0
<4>[ 12.542683] CPU: 0 PID: 196 Comm: systemd-udevd Tainted: G D W
4.16.0-rc5-g639c78d2805b-drmtip_4+ #1
<4>[ 12.543580] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.10.1-0-g8891697-prebuilt.qemu-project.org 04/01/2014
<4>[ 12.544511] Call Trace:
<4>[ 12.544928] dump_stack+0x5f/0x86
<4>[ 12.545384] ___might_sleep+0x1d9/0x240
<4>[ 12.545826] exit_signals+0x1b/0x2a0
<4>[ 12.546304] do_exit+0x93/0xcb0
<4>[ 12.546734] rewind_stack_do_exit+0x17/0x20
<6>[ 13.042212] PCI Interrupt Link [LNKC] enabled at IRQ 10
--
You are receiving this mail because:
You are the QA Contact for the bug.
You are on the CC list for the bug.
You are the assignee for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/intel-gfx-bugs/attachments/20180320/32042ecd/attachment-0001.html>
More information about the intel-gfx-bugs
mailing list