[Bug 106689] New: [CI] ODEBUG: free active (active state 0) object type: timer_list hint: process_timeout+0x0/0x10
bugzilla-daemon at freedesktop.org
bugzilla-daemon at freedesktop.org
Mon May 28 13:59:45 UTC 2018
https://bugs.freedesktop.org/show_bug.cgi?id=106689
Bug ID: 106689
Summary: [CI] ODEBUG: free active (active state 0) object type:
timer_list hint: process_timeout+0x0/0x10
Product: DRI
Version: XOrg git
Hardware: Other
OS: All
Status: NEW
Severity: normal
Priority: medium
Component: DRM/Intel
Assignee: intel-gfx-bugs at lists.freedesktop.org
Reporter: martin.peres at free.fr
QA Contact: intel-gfx-bugs at lists.freedesktop.org
CC: intel-gfx-bugs at lists.freedesktop.org
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_39/fi-bsw-n3050/igt@drm_import_export@flink.html
In the boot log, we can find the following issue, coming from the realtek audio
driver:
<4>[ 14.837853] ------------[ cut here ]------------
<3>[ 14.838298] ODEBUG: free active (active state 0) object type: timer_list
hint: process_timeout+0x0/0x10
<7>[ 14.838427] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.838538] WARNING: CPU: 1 PID: 189 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
<4>[ 14.838639] Modules linked in: snd_hda_codec_realtek(+)
snd_hda_codec_generic i915 snd_hda_intel snd_hda_codec intel_powerclamp
coretemp crct10dif_pclmul crc32_pclmul snd_hwdep ghash_clmulni_intel
snd_hda_core snd_pcm r8169 mii lpc_ich prime_numbers pinctrl_cherryview
<4>[ 14.838943] CPU: 1 PID: 189 Comm: systemd-udevd Not tainted
4.17.0-rc4-gb4c14c0809e8-drmtip_39+ #1
<4>[ 14.839048] Hardware name: /NUC5CPYB, BIOS
PYBSWCEL.86A.0058.2016.1102.1842 11/02/2016
<4>[ 14.839146] RIP: 0010:debug_print_object+0xd7/0x100
<4>[ 14.839208] RSP: 0018:ffffaac080253b60 EFLAGS: 00010082
<4>[ 14.839276] RAX: 0000000000000000 RBX: ffff8cd9b6d14d88 RCX:
0000000000000002
<4>[ 14.839363] RDX: 0000000000000002 RSI: ffffffffba08634e RDI:
00000000ffffffff
<4>[ 14.839449] RBP: ffffffffba247820 R08: 0000000000000000 R09:
0000000000000000
<4>[ 14.839533] R10: ffffaac080253c20 R11: ffffffffba244598 R12:
ffffffffba0a1a97
<4>[ 14.839617] R13: ffffffffb9115d00 R14: ffffaac085865000 R15:
dead000000000100
<4>[ 14.839702] FS: 00007f56f154d680(0000) GS:ffff8cd9bfd00000(0000)
knlGS:0000000000000000
<4>[ 14.839797] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 14.839867] CR2: 00007f4542c8d490 CR3: 0000000175b3e000 CR4:
00000000001006e0
<4>[ 14.839952] Call Trace:
<4>[ 14.839992] ? trace_hardirqs_on_thunk+0x1a/0x1c
<4>[ 14.840058] ? lock_acquire+0xa6/0x210
<4>[ 14.840110] ? debug_check_no_obj_freed+0xa4/0x210
<4>[ 14.840179] debug_check_no_obj_freed+0x194/0x210
<4>[ 14.840247] __vunmap+0xab/0x100
<4>[ 14.840294] load_module+0x2e2/0x2b20
<4>[ 14.840351] ? vfs_read+0x122/0x140
<4>[ 14.840401] ? kernel_read+0x27/0x40
<4>[ 14.840451] ? kernel_read_file+0xee/0x180
<4>[ 14.840511] ? __se_sys_finit_module+0xd3/0xf0
<4>[ 14.840569] __se_sys_finit_module+0xd3/0xf0
<4>[ 14.840634] do_syscall_64+0x55/0x190
<4>[ 14.840685] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 14.840748] RIP: 0033:0x7f56f1077839
<4>[ 14.840795] RSP: 002b:00007ffd6579bf58 EFLAGS: 00000246 ORIG_RAX:
0000000000000139
<4>[ 14.840888] RAX: ffffffffffffffda RBX: 00005646dd579be0 RCX:
00007f56f1077839
<4>[ 14.840974] RDX: 0000000000000000 RSI: 00007f56f0d560e5 RDI:
000000000000000f
<7>[ 14.841087] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.841176] RBP: 00007f56f0d560e5 R08: 0000000000000000 R09:
00007ffd6579c070
<4>[ 14.841182] R10: 000000000000000f R11: 0000000000000246 R12:
0000000000000000
<4>[ 14.841367] R13: 00005646dd59c6a0 R14: 0000000000020000 R15:
00005646dd579be0
<4>[ 14.841459] Code: 02 01 e8 2d 38 05 00 8b 43 10 4d 89 e9 4c 89 e6 8b 4b
14 4c 8b 45 00 48 c7 c7 08 87 0a ba 48 8b 14 c5 e0 45 e4 b9 e8 69 70 bf ff <0f>
0b 48 c7 c7 48 87 0a ba e8 64 c8 c6 ff be 02 00 00 00 48 89
<4>[ 14.841787] irq event stamp: 286790
<4>[ 14.841836] hardirqs last enabled at (286789): [<ffffffffb994878c>]
_raw_spin_unlock_irqrestore+0x4c/0x60
<4>[ 14.841950] hardirqs last disabled at (286790): [<ffffffffb99485fd>]
_raw_spin_lock_irqsave+0xd/0x50
<4>[ 14.842058] softirqs last enabled at (285954): [<ffffffffb9c0032b>]
__do_softirq+0x32b/0x4e1
<4>[ 14.842160] softirqs last disabled at (285947): [<ffffffffb908f6f4>]
irq_exit+0xa4/0xb0
<4>[ 14.842258] WARNING: CPU: 1 PID: 189 at lib/debugobjects.c:339
debug_print_object+0xd7/0x100
<4>[ 14.842357] ---[ end trace 1e828788b9e29e10 ]---
<7>[ 14.843938] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<3>[ 14.846194] ODEBUG: ODEBUG: debug object originally initialized at:
<4>[ 14.846198] schedule_timeout+0x76/0x540
<4>[ 14.846200] msleep+0x33/0x40
<4>[ 14.846214] alc283_init+0xf1/0x120 [snd_hda_codec_realtek]
<4>[ 14.846225] alc_init+0x1f/0x590 [snd_hda_codec_realtek]
<7>[ 14.860163] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.861873] snd_hda_codec_build_controls+0x32/0x200 [snd_hda_codec]
<4>[ 14.861881] hda_codec_driver_probe+0xc1/0x100 [snd_hda_codec]
<4>[ 14.861889] driver_probe_device+0x306/0x480
<7>[ 14.873171] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.873742] __driver_attach+0xb7/0xe0
<4>[ 14.873747] bus_for_each_dev+0x74/0xc0
<7>[ 14.885164] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.885711] bus_add_driver+0x15f/0x250
<4>[ 14.885717] driver_register+0x52/0xc0
<7>[ 14.895368] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.897788] do_one_initcall+0x58/0x370
<4>[ 14.897792] do_init_module+0x56/0x1ea
<4>[ 14.897794] load_module+0x2435/0x2b20
<4>[ 14.897797] __se_sys_finit_module+0xd3/0xf0
<4>[ 14.897799] do_syscall_64+0x55/0x190
<4>[ 14.897805] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<7>[ 14.911696] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status
0x71450064
<4>[ 14.914110] ======================================================
<4>[ 14.914111] WARNING: possible circular locking dependency detected
<4>[ 14.914112] 4.17.0-rc4-gb4c14c0809e8-drmtip_39+ #1 Not tainted
<4>[ 14.914113] ------------------------------------------------------
<4>[ 14.914114] systemd-udevd/189 is trying to acquire lock:
<4>[ 14.914114] (ptrval) ((console_sem).lock){-...}, at:
down_trylock+0xa/0x30
<4>[ 14.914119] but task is already holding lock:
<4>[ 14.914120] (ptrval) (&obj_hash[i].lock){-.-.}, at:
debug_check_no_obj_freed+0xa4/0x210
<4>[ 14.914124] which lock already depends on the new lock.
<4>[ 14.914126] the existing dependency chain (in reverse order) is:
<4>[ 14.914127] -> #3 (&obj_hash[i].lock){-.-.}:
<4>[ 14.914131] __debug_object_init+0x74/0x590
<4>[ 14.914132] hrtimer_init+0x1b/0x160
<4>[ 14.914132] init_dl_task_timer+0x17/0x30
<4>[ 14.914133] __sched_fork.isra.16+0xa4/0xf0
<4>[ 14.914134] init_idle+0x53/0x270
<4>[ 14.914135] sched_init+0x42c/0x49f
<4>[ 14.914136] start_kernel+0x269/0x4c2
<4>[ 14.914136] secondary_startup_64+0xa5/0xb0
<4>[ 14.914138] -> #2 (&rq->lock){-.-.}:
<4>[ 14.914141] task_fork_fair+0x36/0x160
<4>[ 14.914142] sched_fork+0x123/0x280
<4>[ 14.914142] copy_process.part.7+0x5f4/0x1d30
<4>[ 14.914143] _do_fork+0xe2/0x700
<4>[ 14.914144] kernel_thread+0x20/0x30
<4>[ 14.914145] rest_init+0x1d/0x220
<4>[ 14.914146] start_kernel+0x4a2/0x4c2
<4>[ 14.914146] secondary_startup_64+0xa5/0xb0
<4>[ 14.914148] -> #1 (&p->pi_lock){-.-.}:
<4>[ 14.914151] try_to_wake_up+0x37/0x650
<4>[ 14.914152] up+0x3b/0x50
<4>[ 14.914152] __up_console_sem+0x2e/0x50
<4>[ 14.914153] console_unlock+0x32f/0x640
<4>[ 14.914154] register_framebuffer+0x24c/0x350
<4>[ 14.914155] __drm_fb_helper_initial_config_and_unlock+0x22a/0x4a0
<4>[ 14.914156] intel_fbdev_initial_config+0xf/0x20 [i915]
<4>[ 14.914157] async_run_entry_fn+0x34/0x160
<4>[ 14.914158] process_one_work+0x229/0x6a0
<4>[ 14.914159] worker_thread+0x35/0x380
<4>[ 14.914159] kthread+0x119/0x130
<4>[ 14.914160] ret_from_fork+0x3a/0x50
<4>[ 14.914161] -> #0 ((console_sem).lock){-...}:
<4>[ 14.914165] _raw_spin_lock_irqsave+0x33/0x50
<4>[ 14.914165] down_trylock+0xa/0x30
<4>[ 14.914166] __down_trylock_console_sem+0x20/0x80
<4>[ 14.914167] console_trylock+0xe/0x60
<4>[ 14.914168] vprintk_emit+0x22e/0x4d0
<4>[ 14.914169] printk+0x4d/0x69
<4>[ 14.914169] __warn_printk+0x46/0x90
<4>[ 14.914170] debug_print_object+0xd7/0x100
<4>[ 14.914171] debug_check_no_obj_freed+0x194/0x210
<4>[ 14.914172] __vunmap+0xab/0x100
<4>[ 14.914173] load_module+0x2e2/0x2b20
<4>[ 14.914174] __se_sys_finit_module+0xd3/0xf0
<4>[ 14.914174] do_syscall_64+0x55/0x190
<4>[ 14.914175] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 14.914177] other info that might help us debug this:
<4>[ 14.914178] Chain exists of:
<4>[ 14.914179] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock
<4>[ 14.914184] Possible unsafe locking scenario:
<4>[ 14.914185] CPU0 CPU1
<4>[ 14.914186] ---- ----
<4>[ 14.914187] lock(&obj_hash[i].lock);
<4>[ 14.914189] lock(&rq->lock);
<4>[ 14.914191] lock(&obj_hash[i].lock);
<4>[ 14.914193] lock((console_sem).lock);
<4>[ 14.914196] *** DEADLOCK ***
<4>[ 14.914197] 1 lock held by systemd-udevd/189:
<4>[ 14.914198] #0: (ptrval) (&obj_hash[i].lock){-.-.}, at:
debug_check_no_obj_freed+0xa4/0x210
<4>[ 14.914202] stack backtrace:
<4>[ 14.914204] CPU: 1 PID: 189 Comm: systemd-udevd Not tainted
4.17.0-rc4-gb4c14c0809e8-drmtip_39+ #1
<4>[ 14.914205] Hardware name: /NUC5CPYB, BIOS
PYBSWCEL.86A.0058.2016.1102.1842 11/02/2016
<4>[ 14.914205] Call Trace:
<4>[ 14.914206] dump_stack+0x67/0x9b
<4>[ 14.914207] print_circular_bug.isra.18+0x1c8/0x2b0
<4>[ 14.914208] __lock_acquire+0x1897/0x1b50
<4>[ 14.914209] ? lock_acquire+0xa6/0x210
<4>[ 14.914209] lock_acquire+0xa6/0x210
<4>[ 14.914210] ? down_trylock+0xa/0x30
<4>[ 14.914211] ? vprintk_emit+0x22e/0x4d0
<4>[ 14.914212] _raw_spin_lock_irqsave+0x33/0x50
<4>[ 14.914213] ? down_trylock+0xa/0x30
<4>[ 14.914213] down_trylock+0xa/0x30
<4>[ 14.914214] __down_trylock_console_sem+0x20/0x80
<4>[ 14.914215] console_trylock+0xe/0x60
<4>[ 14.914216] vprintk_emit+0x22e/0x4d0
<4>[ 14.914217] ? collect_expired_timers+0xa0/0xa0
<4>[ 14.914217] printk+0x4d/0x69
<4>[ 14.914218] ? collect_expired_timers+0xa0/0xa0
<4>[ 14.914219] __warn_printk+0x46/0x90
<4>[ 14.914220] ? collect_expired_timers+0xa0/0xa0
<4>[ 14.914221] debug_print_object+0xd7/0x100
<4>[ 14.914222] ? trace_hardirqs_on_thunk+0x1a/0x1c
<4>[ 14.914222] ? lock_acquire+0xa6/0x210
<4>[ 14.914223] ? debug_check_no_obj_freed+0xa4/0x210
<4>[ 14.914224] debug_check_no_obj_freed+0x194/0x210
<4>[ 14.914225] __vunmap+0xab/0x100
<4>[ 14.914226] load_module+0x2e2/0x2b20
<4>[ 14.914226] ? vfs_read+0x122/0x140
<4>[ 14.914227] ? kernel_read+0x27/0x40
<4>[ 14.914228] ? kernel_read_file+0xee/0x180
<4>[ 14.914229] ? __se_sys_finit_module+0xd3/0xf0
<4>[ 14.914230] __se_sys_finit_module+0xd3/0xf0
<4>[ 14.914230] do_syscall_64+0x55/0x190
<4>[ 14.914231] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 14.914232] RIP: 0033:0x7f56f1077839
<4>[ 14.914233] RSP: 002b:00007ffd6579bf58 EFLAGS: 00000246 ORIG_RAX:
0000000000000139
<4>[ 14.914235] RAX: ffffffffffffffda RBX: 00005646dd579be0 RCX:
00007f56f1077839
<4>[ 14.914236] RDX: 0000000000000000 RSI: 00007f56f0d560e5 RDI:
000000000000000f
<4>[ 14.914237] RBP: 00007f56f0d560e5 R08: 0000000000000000 R09:
00007ffd6579c070
<4>[ 14.914238] R10: 000000000000000f R11: 0000000000000246 R12:
0000000000000000
<4>[ 14.914239] R13: 00005646dd59c6a0 R14: 0000000000020000 R15:
00005646dd579be0
Filing this bug first here to see if we can reproduce it, before sending it to
the audio guys.
--
You are receiving this mail because:
You are the assignee for the bug.
You are on the CC list for the bug.
You are the QA Contact for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/intel-gfx-bugs/attachments/20180528/2b237503/attachment-0001.html>
More information about the intel-gfx-bugs
mailing list