<html>
<head>
<base href="https://bugs.freedesktop.org/">
</head>
<body><span class="vcard"><a class="email" href="mailto:martin.peres@free.fr" title="Martin Peres <martin.peres@free.fr>"> <span class="fn">Martin Peres</span></a>
</span> changed
<a class="bz_bug_link
bz_status_REOPENED "
title="REOPENED - [CI] igt@gem_* - dmesg-warn - ODEBUG: free active (active state 0) object type: hrtimer hint: hrtimer_wakeup"
href="https://bugs.freedesktop.org/show_bug.cgi?id=106353">bug 106353</a>
<br>
<table border="1" cellspacing="0" cellpadding="8">
<tr>
<th>What</th>
<th>Removed</th>
<th>Added</th>
</tr>
<tr>
<td style="text-align:right;">Resolution</td>
<td>WORKSFORME
</td>
<td>---
</td>
</tr>
<tr>
<td style="text-align:right;">Status</td>
<td>RESOLVED
</td>
<td>REOPENED
</td>
</tr>
<tr>
<td style="text-align:right;">i915 platform</td>
<td>
</td>
<td>KBL
</td>
</tr></table>
<p>
<div>
<b><a class="bz_bug_link
bz_status_REOPENED "
title="REOPENED - [CI] igt@gem_* - dmesg-warn - ODEBUG: free active (active state 0) object type: hrtimer hint: hrtimer_wakeup"
href="https://bugs.freedesktop.org/show_bug.cgi?id=106353#c5">Comment # 5</a>
on <a class="bz_bug_link
bz_status_REOPENED "
title="REOPENED - [CI] igt@gem_* - dmesg-warn - ODEBUG: free active (active state 0) object type: hrtimer hint: hrtimer_wakeup"
href="https://bugs.freedesktop.org/show_bug.cgi?id=106353">bug 106353</a>
from <span class="vcard"><a class="email" href="mailto:martin.peres@free.fr" title="Martin Peres <martin.peres@free.fr>"> <span class="fn">Martin Peres</span></a>
</span></b>
<pre>Definitely not a one-off, and definitely visible right now :)
<a href="https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_4266/shard-kbl4/igt@gem_exec_await@wide-contexts.html">https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_4266/shard-kbl4/igt@gem_exec_await@wide-contexts.html</a>
[ 148.822603] ------------[ cut here ]------------
[ 148.822915] ODEBUG: free active (active state 0) object type: hrtimer hint:
hrtimer_wakeup+0x0/0x20
[ 148.822929] WARNING: CPU: 0 PID: 6 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
[ 148.822935] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek
snd_hda_codec_generic i915 snd_hda_intel x86_pkg_temp_thermal intel_powerclamp
coretemp snd_hda_codec crct10dif_pclmul crc32_pclmul snd_hwdep snd_hda_core
btusb ghash_clmulni_intel btrtl btbcm btintel snd_pcm bluetooth e1000e
ecdh_generic mei_me mei prime_numbers
[ 148.822972] CPU: 0 PID: 6 Comm: kworker/u8:0 Tainted: G U
4.17.0-rc7-CI-CI_DRM_4266+ #1
[ 148.822979] Hardware name: /NUC7i5BNB, BIOS
BNKBL357.86A.0054.2017.1025.1822 10/25/2017
[ 148.823003] Workqueue: i915 __i915_gem_free_work [i915]
[ 148.823009] RIP: 0010:debug_print_object+0xd7/0x100
[ 148.823014] RSP: 0018:ffffc90000077be8 EFLAGS: 00010086
[ 148.823019] RAX: 0000000000000000 RBX: ffff880157d56488 RCX:
0000000000000002
[ 148.823025] RDX: 0000000080000002 RSI: ffffffff820c48a5 RDI:
00000000ffffffff
[ 148.823031] RBP: ffffffff82248480 R08: 0000000000000000 R09:
0000000000000000
[ 148.823036] R10: ffffc90000077ca8 R11: ffffffff82243e18 R12:
ffffffff820c0b1f
[ 148.823042] R13: ffffffff81115790 R14: ffffc90003470000 R15:
dead000000000100
[ 148.823048] FS: 0000000000000000(0000) GS:ffff88027ec00000(0000)
knlGS:0000000000000000
[ 148.823055] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 148.823060] CR2: 00007f7723cbd9a8 CR3: 0000000005210006 CR4:
00000000003606f0
[ 148.823065] Call Trace:
[ 148.823070] ? mark_held_locks+0x50/0x80
[ 148.823075] ? _raw_spin_unlock_irqrestore+0x4c/0x60
[ 148.823080] ? trace_hardirqs_on_caller+0xe0/0x1b0
[ 148.823086] ? lock_acquire+0xa6/0x210
[ 148.823090] ? debug_check_no_obj_freed+0xa4/0x210
[ 148.823096] debug_check_no_obj_freed+0x194/0x210
[ 148.823103] __vunmap+0xab/0x100
[ 148.823125] __i915_gem_object_put_pages+0x1ec/0x200 [i915]
[ 148.823148] __i915_gem_free_objects+0x275/0x780 [i915]
[ 148.823171] __i915_gem_free_work+0x5d/0x90 [i915]
[ 148.823177] process_one_work+0x229/0x6a0
[ 148.823184] worker_thread+0x35/0x380
[ 148.823189] ? process_one_work+0x6a0/0x6a0
[ 148.823193] kthread+0x119/0x130
[ 148.823197] ? kthread_flush_work_fn+0x10/0x10
[ 148.823203] ret_from_fork+0x3a/0x50
[ 148.823208] Code: 02 01 e8 3d 38 05 00 8b 43 10 4d 89 e9 4c 89 e6 8b 4b 14
4c 8b 45 00 48 c7 c7 08 2f 0d 82 48 8b 14 c5 40 cb e6 81 e8 19 01 bf ff <0f> 0b
48 c7 c7 48 2f 0d 82 e8 64 59 c6 ff be 02 00 00 00 48 89
[ 148.823257] irq event stamp: 2465622
[ 148.823262] hardirqs last enabled at (2465621): [<ffffffff81930b6c>]
_raw_spin_unlock_irqrestore+0x4c/0x60
[ 148.823270] hardirqs last disabled at (2465622): [<ffffffff819309dd>]
_raw_spin_lock_irqsave+0xd/0x50
[ 148.823278] softirqs last enabled at (2461560): [<ffffffff81c0032b>]
__do_softirq+0x32b/0x4e1
[ 148.823286] softirqs last disabled at (2461553): [<ffffffff8108c284>]
irq_exit+0xa4/0xb0
[ 148.823293] WARNING: CPU: 0 PID: 6 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
[ 148.823300] ---[ end trace 7b673478a9a0fd9b ]---
[ 148.823304] ODEBUG: ODEBUG: debug object originally initialized at:
[ 148.823311] futex_wait+0x77/0x240
[ 148.823315] do_futex+0x486/0xb10
[ 148.823320] __se_sys_futex+0x128/0x170
[ 148.823324] do_syscall_64+0x55/0x190
[ 148.823328] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 148.823334] ======================================================
[ 148.823335] WARNING: possible circular locking dependency detected
[ 148.823335] 4.17.0-rc7-CI-CI_DRM_4266+ #1 Tainted: G U
[ 148.823335] ------------------------------------------------------
[ 148.823336] kworker/u8:0/6 is trying to acquire lock:
[ 148.823336] 00000000f82870ee ((console_sem).lock){-...}, at:
down_trylock+0xa/0x30
[ 148.823338] but task is already holding lock:
[ 148.823338] 000000007fd8375f (&obj_hash[i].lock){-.-.}, at:
debug_check_no_obj_freed+0xa4/0x210
[ 148.823339] which lock already depends on the new lock.
[ 148.823340] the existing dependency chain (in reverse order) is:
[ 148.823341] -> #3 (&obj_hash[i].lock){-.-.}:
[ 148.823342] __debug_object_init+0x74/0x590
[ 148.823342] hrtimer_init+0x1b/0x160
[ 148.823342] init_dl_task_timer+0x17/0x30
[ 148.823343] __sched_fork.isra.16+0xa4/0xf0
[ 148.823343] init_idle+0x53/0x270
[ 148.823343] sched_init+0x42c/0x49f
[ 148.823343] start_kernel+0x269/0x4bb
[ 148.823344] secondary_startup_64+0xa5/0xb0
[ 148.823344] -> #2 (&rq->lock){-.-.}:
[ 148.823345] task_fork_fair+0x36/0x160
[ 148.823346] sched_fork+0x123/0x280
[ 148.823346] copy_process.part.7+0x5f4/0x1d30
[ 148.823346] _do_fork+0xe2/0x700
[ 148.823346] kernel_thread+0x20/0x30
[ 148.823347] rest_init+0x1d/0x220
[ 148.823347] start_kernel+0x49b/0x4bb
[ 148.823347] secondary_startup_64+0xa5/0xb0
[ 148.823348] -> #1 (&p->pi_lock){-.-.}:
[ 148.823349] try_to_wake_up+0x37/0x650
[ 148.823349] up+0x3b/0x50
[ 148.823349] __up_console_sem+0x2e/0x50
[ 148.823350] console_unlock+0x32f/0x640
[ 148.823350] register_framebuffer+0x24c/0x350
[ 148.823350] __drm_fb_helper_initial_config_and_unlock+0x22a/0x4a0
[ 148.823351] intel_fbdev_initial_config+0xf/0x20 [i915]
[ 148.823351] async_run_entry_fn+0x34/0x160
[ 148.823351] process_one_work+0x229/0x6a0
[ 148.823351] worker_thread+0x35/0x380
[ 148.823352] kthread+0x119/0x130
[ 148.823352] ret_from_fork+0x3a/0x50
[ 148.823352] -> #0 ((console_sem).lock){-...}:
[ 148.823354] _raw_spin_lock_irqsave+0x33/0x50
[ 148.823354] down_trylock+0xa/0x30
[ 148.823354] __down_trylock_console_sem+0x20/0x80
[ 148.823354] console_trylock+0xe/0x60
[ 148.823355] vprintk_emit+0x22e/0x4d0
[ 148.823355] printk+0x4d/0x69
[ 148.823355] __warn_printk+0x46/0x90
[ 148.823355] debug_print_object+0xd7/0x100
[ 148.823356] debug_check_no_obj_freed+0x194/0x210
[ 148.823356] __vunmap+0xab/0x100
[ 148.823356] __i915_gem_object_put_pages+0x1ec/0x200 [i915]
[ 148.823357] __i915_gem_free_objects+0x275/0x780 [i915]
[ 148.823357] __i915_gem_free_work+0x5d/0x90 [i915]
[ 148.823357] process_one_work+0x229/0x6a0
[ 148.823358] worker_thread+0x35/0x380
[ 148.823358] kthread+0x119/0x130
[ 148.823358] ret_from_fork+0x3a/0x50
[ 148.823359] other info that might help us debug this:
[ 148.823359] Chain exists of:
[ 148.823359] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock
[ 148.823361] Possible unsafe locking scenario:
[ 148.823362] CPU0 CPU1
[ 148.823362] ---- ----
[ 148.823362] lock(&obj_hash[i].lock);
[ 148.823363] lock(&rq->lock);
[ 148.823364] lock(&obj_hash[i].lock);
[ 148.823364] lock((console_sem).lock);
[ 148.823365] *** DEADLOCK ***
[ 148.823366] 4 locks held by kworker/u8:0/6:
[ 148.823366] #0: 0000000014cc212b ((wq_completion)"i915"){+.+.}, at:
process_one_work+0x1a3/0x6a0
[ 148.823367] #1: 0000000071ed54ba
((work_completion)(&i915->mm.free_work)){+.+.}, at:
process_one_work+0x1a3/0x6a0
[ 148.823369] #2: 0000000020c47fc7 (&obj->mm.lock){+.+.}, at:
__i915_gem_object_put_pages+0x4f/0x200 [i915]
[ 148.823370] #3: 000000007fd8375f (&obj_hash[i].lock){-.-.}, at:
debug_check_no_obj_freed+0xa4/0x210
[ 148.823372] stack backtrace:
[ 148.823372] CPU: 0 PID: 6 Comm: kworker/u8:0 Tainted: G U
4.17.0-rc7-CI-CI_DRM_4266+ #1
[ 148.823372] Hardware name: /NUC7i5BNB, BIOS
BNKBL357.86A.0054.2017.1025.1822 10/25/2017
[ 148.823373] Workqueue: i915 __i915_gem_free_work [i915]
[ 148.823373] Call Trace:
[ 148.823373] dump_stack+0x67/0x9b
[ 148.823374] print_circular_bug.isra.18+0x1c8/0x2b0
[ 148.823374] __lock_acquire+0x1897/0x1b50
[ 148.823374] ? lock_acquire+0xa6/0x210
[ 148.823375] lock_acquire+0xa6/0x210
[ 148.823375] ? down_trylock+0xa/0x30
[ 148.823375] ? sched_clock_cpu+0x10/0xe0
[ 148.823375] ? vprintk_emit+0x22e/0x4d0
[ 148.823376] _raw_spin_lock_irqsave+0x33/0x50
[ 148.823376] ? down_trylock+0xa/0x30
[ 148.823376] down_trylock+0xa/0x30
[ 148.823377] __down_trylock_console_sem+0x20/0x80
[ 148.823377] console_trylock+0xe/0x60
[ 148.823377] vprintk_emit+0x22e/0x4d0
[ 148.823377] ? clock_was_set_work+0x20/0x20
[ 148.823378] printk+0x4d/0x69
[ 148.823378] ? clock_was_set_work+0x20/0x20
[ 148.823378] __warn_printk+0x46/0x90
[ 148.823378] ? clock_was_set_work+0x20/0x20
[ 148.823379] debug_print_object+0xd7/0x100
[ 148.823379] ? mark_held_locks+0x50/0x80
[ 148.823379] ? _raw_spin_unlock_irqrestore+0x4c/0x60
[ 148.823380] ? trace_hardirqs_on_caller+0xe0/0x1b0
[ 148.823380] ? lock_acquire+0xa6/0x210
[ 148.823380] ? debug_check_no_obj_freed+0xa4/0x210
[ 148.823380] debug_check_no_obj_freed+0x194/0x210
[ 148.823381] __vunmap+0xab/0x100
[ 148.823381] __i915_gem_object_put_pages+0x1ec/0x200 [i915]
[ 148.823381] __i915_gem_free_objects+0x275/0x780 [i915]
[ 148.823382] __i915_gem_free_work+0x5d/0x90 [i915]
[ 148.823382] process_one_work+0x229/0x6a0
[ 148.823382] worker_thread+0x35/0x380
[ 148.823382] ? process_one_work+0x6a0/0x6a0
[ 148.823383] kthread+0x119/0x130
[ 148.823383] ? kthread_flush_work_fn+0x10/0x10
[ 148.823383] ret_from_fork+0x3a/0x50
[ 148.827461] ------------[ cut here ]------------
[ 148.827470] ODEBUG: free active (active state 0) object type: hrtimer hint:
hrtimer_wakeup+0x0/0x20
[ 148.827484] WARNING: CPU: 0 PID: 6 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
[ 148.827491] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek
snd_hda_codec_generic i915 snd_hda_intel x86_pkg_temp_thermal intel_powerclamp
coretemp snd_hda_codec crct10dif_pclmul crc32_pclmul snd_hwdep snd_hda_core
btusb ghash_clmulni_intel btrtl btbcm btintel snd_pcm bluetooth e1000e
ecdh_generic mei_me mei prime_numbers
[ 148.827531] CPU: 0 PID: 6 Comm: kworker/u8:0 Tainted: G U W
4.17.0-rc7-CI-CI_DRM_4266+ #1
[ 148.827538] Hardware name: /NUC7i5BNB, BIOS
BNKBL357.86A.0054.2017.1025.1822 10/25/2017
[ 148.827575] Workqueue: i915 __i915_gem_free_work [i915]
[ 148.827583] RIP: 0010:debug_print_object+0xd7/0x100
[ 148.827587] RSP: 0000:ffffc90000077be8 EFLAGS: 00010086
[ 148.827593] RAX: 0000000000000000 RBX: ffff880158d22908 RCX:
0000000000000002
[ 148.827599] RDX: 0000000080000002 RSI: ffffffff820c48a5 RDI:
00000000ffffffff
[ 148.827604] RBP: ffffffff82248480 R08: 0000000000000000 R09:
0000000000000000
[ 148.827610] R10: ffffc90000077ca8 R11: ffffffff82243e18 R12:
ffffffff820c0b1f
[ 148.827616] R13: ffffffff81115790 R14: ffffc90003470000 R15:
dead000000000100
[ 148.827622] FS: 0000000000000000(0000) GS:ffff88027ec00000(0000)
knlGS:0000000000000000
[ 148.827629] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 148.827634] CR2: 00007fc0178ddb98 CR3: 0000000005210006 CR4:
00000000003606f0
[ 148.827639] Call Trace:
[ 148.827645] ? lock_acquire+0xa6/0x210
[ 148.827650] ? lock_acquire+0xa6/0x210
[ 148.827655] ? debug_check_no_obj_freed+0xa4/0x210
[ 148.827660] ? __free_object+0xa9/0xb0
[ 148.827665] debug_check_no_obj_freed+0x194/0x210
[ 148.827672] __vunmap+0xab/0x100
[ 148.827704] __i915_gem_object_put_pages+0x1ec/0x200 [i915]
[ 148.827730] __i915_gem_free_objects+0x275/0x780 [i915]
[ 148.827754] __i915_gem_free_work+0x5d/0x90 [i915]
[ 148.827762] process_one_work+0x229/0x6a0
[ 148.827768] worker_thread+0x35/0x380
[ 148.827773] ? process_one_work+0x6a0/0x6a0
[ 148.827778] kthread+0x119/0x130
[ 148.827783] ? kthread_flush_work_fn+0x10/0x10
[ 148.827788] ret_from_fork+0x3a/0x50
[ 148.827794] Code: 02 01 e8 3d 38 05 00 8b 43 10 4d 89 e9 4c 89 e6 8b 4b 14
4c 8b 45 00 48 c7 c7 08 2f 0d 82 48 8b 14 c5 40 cb e6 81 e8 19 01 bf ff <0f> 0b
48 c7 c7 48 2f 0d 82 e8 64 59 c6 ff be 02 00 00 00 48 89
[ 148.827844] irq event stamp: 2465622
[ 148.827849] hardirqs last enabled at (2465621): [<ffffffff81930b6c>]
_raw_spin_unlock_irqrestore+0x4c/0x60
[ 148.827857] hardirqs last disabled at (2465622): [<ffffffff819309dd>]
_raw_spin_lock_irqsave+0xd/0x50
[ 148.827865] softirqs last enabled at (2461560): [<ffffffff81c0032b>]
__do_softirq+0x32b/0x4e1
[ 148.827873] softirqs last disabled at (2461553): [<ffffffff8108c284>]
irq_exit+0xa4/0xb0
[ 148.827881] WARNING: CPU: 0 PID: 6 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
[ 148.827887] ---[ end trace 7b673478a9a0fd9c ]---</pre>
</div>
</p>
<hr>
<span>You are receiving this mail because:</span>
<ul>
<li>You are the assignee for the bug.</li>
<li>You are on the CC list for the bug.</li>
<li>You are the QA Contact for the bug.</li>
</ul>
</body>
</html>