Bug 103608

Summary: [CI] igt@kms_flip@wf_vblank-vs-dpms[-s-interruptible] - Incomplete - INFO: task kms_flip:8510 blocked for more than 60 seconds.
Product: DRI Reporter: Marta Löfstedt <marta.lofstedt>
Component: DRM/IntelAssignee: Intel GFX Bugs mailing list <intel-gfx-bugs>
Status: CLOSED FIXED QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: normal    
Priority: medium CC: intel-gfx-bugs
Version: DRI git   
Hardware: Other   
OS: All   
Whiteboard: ReadyForDev
i915 platform: HSW i915 features: display/Other

Description Marta Löfstedt 2017-11-07 10:46:16 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3316/shard-hsw8/igt@kms_flip@wf_vblank-vs-dpms.html

<3>[ 1353.212534] INFO: task kms_flip:8510 blocked for more than 60 seconds.
<3>[ 1353.212535]       Tainted: G     U  W       4.14.0-rc8-CI-CI_DRM_3316+ #1
<3>[ 1353.212536] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 1353.212536] kms_flip        D    0  8510   8280 0x00000000
<4>[ 1353.212538] Call Trace:
<4>[ 1353.212542]  __schedule+0x3c3/0xaf0
<4>[ 1353.212544]  schedule+0x40/0x90
<4>[ 1353.212545]  schedule_preempt_disabled+0x18/0x30
<4>[ 1353.212547]  __mutex_lock+0x2bb/0x9b0
<4>[ 1353.212549]  ? drm_mode_getconnector+0x15c/0x3c0
<4>[ 1353.212551]  ? mutex_unlock+0x12/0x20
<4>[ 1353.212553]  mutex_lock_nested+0x1b/0x20
<4>[ 1353.212554]  ? mutex_lock_nested+0x1b/0x20
<4>[ 1353.212555]  drm_mode_getconnector+0x15c/0x3c0
<4>[ 1353.212557]  ? drm_mode_connector_property_set_ioctl+0x40/0x40
<4>[ 1353.212559]  drm_ioctl_kernel+0x69/0xb0
<4>[ 1353.212560]  drm_ioctl+0x2f9/0x3d0
<4>[ 1353.212561]  ? drm_mode_connector_property_set_ioctl+0x40/0x40
<4>[ 1353.212564]  ? __vfs_read+0x28/0x120
<4>[ 1353.212567]  do_vfs_ioctl+0x94/0x670
<4>[ 1353.212568]  ? vfs_read+0x12d/0x150
<4>[ 1353.212569]  SyS_ioctl+0x41/0x70
<4>[ 1353.212572]  entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[ 1353.212573] RIP: 0033:0x7fc4537bc587
<4>[ 1353.212573] RSP: 002b:00007ffe6d4cdfc8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[ 1353.212574] RAX: ffffffffffffffda RBX: 00007ffe6d4cde80 RCX: 00007fc4537bc587
<4>[ 1353.212575] RDX: 00007ffe6d4ce000 RSI: 00000000c05064a7 RDI: 0000000000000003
<4>[ 1353.212575] RBP: 00007ffe6d4cde70 R08: 000055bcff51d7d0 R09: 0000000000000000
<4>[ 1353.212576] R10: 0000000000000073 R11: 0000000000000246 R12: 000055bcfe56fa68
<4>[ 1353.212577] R13: 00007ffe6d4ce040 R14: 0000000000000000 R15: ffffffffffffffff
<4>[ 1353.212579] INFO: lockdep is turned off.
<4>[ 1353.212579] NMI backtrace for cpu 0
<4>[ 1353.212581] CPU: 0 PID: 66 Comm: khungtaskd Tainted: G     U  W       4.14.0-rc8-CI-CI_DRM_3316+ #1
<4>[ 1353.212581] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 1353.212582] Call Trace:
<4>[ 1353.212584]  dump_stack+0x68/0x9f
<4>[ 1353.212585]  nmi_cpu_backtrace+0xbe/0xc0
<4>[ 1353.212587]  ? irq_force_complete_move+0xe0/0xe0
<4>[ 1353.212589]  nmi_trigger_cpumask_backtrace+0xc0/0x100
<4>[ 1353.212590]  arch_trigger_cpumask_backtrace+0x19/0x20
<4>[ 1353.212592]  watchdog+0x454/0x610
<4>[ 1353.212593]  kthread+0x114/0x150
<4>[ 1353.212594]  ? reset_hung_task_detector+0x20/0x20
<4>[ 1353.212595]  ? kthread_create_on_node+0x40/0x40
<4>[ 1353.212596]  ret_from_fork+0x27/0x40
<6>[ 1353.212599] Sending NMI from CPU 0 to CPUs 1-7:
<4>[ 1353.212718] NMI backtrace for cpu 5 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.212720] NMI backtrace for cpu 2 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.212721] NMI backtrace for cpu 7 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.212723] NMI backtrace for cpu 3 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.212724] NMI backtrace for cpu 1 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.212726] NMI backtrace for cpu 6 skipped: idling at pc 0xffffffff81911925
<4>[ 1353.213601] NMI backtrace for cpu 4
<4>[ 1353.213601] CPU: 4 PID: 7402 Comm: kworker/4:0 Tainted: G     U  W       4.14.0-rc8-CI-CI_DRM_3316+ #1
<4>[ 1353.213602] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 1353.213602] Workqueue: events i915_hpd_poll_init_work [i915]
<4>[ 1353.213603] task: ffff8803f9bd2800 task.stack: ffffc90000388000
<4>[ 1353.213603] RIP: 0010:io_serial_in+0x18/0x20
<4>[ 1353.213603] RSP: 0018:ffffc9000038bad8 EFLAGS: 00000002
<4>[ 1353.213604] RAX: 0000000080000000 RBX: ffffffff836212c0 RCX: 0000000000000000
<4>[ 1353.213604] RDX: 00000000000003fd RSI: 0000000000000005 RDI: ffffffff836212c0
<4>[ 1353.213604] RBP: ffffc9000038bad8 R08: 0000000000000001 R09: 0000000000000001
<4>[ 1353.213605] R10: ffffc9000038bac8 R11: ffffffff815b0141 R12: 00000000000026fe
<4>[ 1353.213605] R13: 0000000000000020 R14: ffffffff82ca4efa R15: ffffffff836212c0
<4>[ 1353.213606] FS:  0000000000000000(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[ 1353.213606] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 1353.213606] CR2: 00007fc45046c220 CR3: 0000000003e0f001 CR4: 00000000001606e0
<4>[ 1353.213606] Call Trace:
<4>[ 1353.213607]  wait_for_xmitr+0x41/0xa0
<4>[ 1353.213607]  serial8250_console_putchar+0x1c/0x30
<4>[ 1353.213607]  ? wait_for_xmitr+0xa0/0xa0
<4>[ 1353.213607]  uart_console_write+0x30/0x70
<4>[ 1353.213608]  serial8250_console_write+0xd9/0x270
<4>[ 1353.213608]  ? vt_console_print+0x225/0x3b0
<4>[ 1353.213608]  ? msg_print_text+0x9d/0x100
<4>[ 1353.213609]  univ8250_console_write+0x26/0x30
<4>[ 1353.213609]  console_unlock+0x430/0x570
<4>[ 1353.213609]  vprintk_emit+0x254/0x3b0
<4>[ 1353.213609]  ? wake_up_q+0x59/0x80
<4>[ 1353.213610]  vprintk_default+0x1f/0x30
<4>[ 1353.213610]  vprintk_func+0x2c/0x90
<4>[ 1353.213610]  printk+0x43/0x4b
<4>[ 1353.213610]  ? drm_helper_hpd_irq_event+0xcc/0x110
<4>[ 1353.213611]  drm_printk+0x8e/0x90
<4>[ 1353.213611]  drm_helper_hpd_irq_event+0xcc/0x110
<4>[ 1353.213611]  i915_hpd_poll_init_work+0xc5/0x100 [i915]
<4>[ 1353.213612]  process_one_work+0x221/0x650
<4>[ 1353.213612]  worker_thread+0x4e/0x3c0
<4>[ 1353.213612]  kthread+0x114/0x150
<4>[ 1353.213612]  ? process_one_work+0x650/0x650
<4>[ 1353.213613]  ? kthread_create_on_node+0x40/0x40
<4>[ 1353.213613]  ret_from_fork+0x27/0x40
<4>[ 1353.213613] Code: 48 89 e5 d3 e6 48 63 f6 48 03 77 40 8b 06 5d c3 0f 1f 00 0f 1f 44 00 00 0f b6 8f d1 00 00 00 8b 57 38 55 48 89 e5 d3 e6 01 f2 ec <0f> b6 c0 5d c3 0f 1f 00 0f 1f 44 00 00 0f b6 8f d1 00 00 00 89 
<0>[ 1353.213626] Kernel panic - not syncing: hung_task: blocked tasks
<4>[ 1353.213627] CPU: 0 PID: 66 Comm: khungtaskd Tainted: G     U  W       4.14.0-rc8-CI-CI_DRM_3316+ #1
<4>[ 1353.213627] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 1353.213628] Call Trace:
<4>[ 1353.213629]  dump_stack+0x68/0x9f
<4>[ 1353.213631]  panic+0xd4/0x21d
<4>[ 1353.213633]  watchdog+0x460/0x610
<4>[ 1353.213635]  kthread+0x114/0x150
<4>[ 1353.213636]  ? reset_hung_task_detector+0x20/0x20
<4>[ 1353.213636]  ? kthread_create_on_node+0x40/0x40
<4>[ 1353.213637]  ret_from_fork+0x27/0x40
<0>[ 1353.217854] Kernel Offset: disabled
Comment 1 Marta Löfstedt 2017-11-07 10:47:13 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3315/shard-hsw8/igt@kms_flip@wf_vblank-vs-dpms-interruptible.html

<3>[  553.953286] INFO: task kms_flip:3392 blocked for more than 60 seconds.
<3>[  553.953287]       Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3315+ #1
<3>[  553.953288] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[  553.953288] kms_flip        D    0  3392   2292 0x00000004
<4>[  553.953290] Call Trace:
<4>[  553.953294]  __schedule+0x3c3/0xaf0
<4>[  553.953295]  schedule+0x40/0x90
<4>[  553.953296]  schedule_preempt_disabled+0x18/0x30
<4>[  553.953298]  __mutex_lock+0x2bb/0x9b0
<4>[  553.953300]  ? drm_mode_getconnector+0x15c/0x3c0
<4>[  553.953302]  ? mutex_unlock+0x12/0x20
<4>[  553.953303]  mutex_lock_nested+0x1b/0x20
<4>[  553.953304]  ? mutex_lock_nested+0x1b/0x20
<4>[  553.953305]  drm_mode_getconnector+0x15c/0x3c0
<4>[  553.953307]  ? drm_mode_connector_property_set_ioctl+0x40/0x40
<4>[  553.953308]  drm_ioctl_kernel+0x69/0xb0
<4>[  553.953310]  drm_ioctl+0x2f9/0x3d0
<4>[  553.953310]  ? drm_mode_connector_property_set_ioctl+0x40/0x40
<4>[  553.953313]  ? __vfs_read+0x28/0x120
<4>[  553.953315]  do_vfs_ioctl+0x94/0x670
<4>[  553.953316]  ? vfs_read+0x12d/0x150
<4>[  553.953317]  SyS_ioctl+0x41/0x70
<4>[  553.953319]  entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[  553.953320] RIP: 0033:0x7f983e910587
<4>[  553.953320] RSP: 002b:00007ffd130688d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[  553.953321] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f983e910587
<4>[  553.953321] RDX: 00007ffd13068910 RSI: 00000000c05064a7 RDI: 0000000000000003
<4>[  553.953322] RBP: 00007ffd130689f0 R08: 000056182f177ca0 R09: 0000000000000000
<4>[  553.953322] R10: 0000000000000073 R11: 0000000000000246 R12: 00000000c01064ab
<4>[  553.953323] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000000000004
<4>[  553.953324] INFO: lockdep is turned off.
<4>[  553.953325] NMI backtrace for cpu 1
<4>[  553.953326] CPU: 1 PID: 66 Comm: khungtaskd Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3315+ #1
<4>[  553.953326] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  553.953327] Call Trace:
<4>[  553.953328]  dump_stack+0x68/0x9f
<4>[  553.953330]  nmi_cpu_backtrace+0xbe/0xc0
<4>[  553.953333]  ? irq_force_complete_move+0xe0/0xe0
<4>[  553.953333]  nmi_trigger_cpumask_backtrace+0xc0/0x100
<4>[  553.953335]  arch_trigger_cpumask_backtrace+0x19/0x20
<4>[  553.953336]  watchdog+0x454/0x610
<4>[  553.953338]  kthread+0x114/0x150
<4>[  553.953338]  ? reset_hung_task_detector+0x20/0x20
<4>[  553.953339]  ? kthread_create_on_node+0x40/0x40
<4>[  553.953340]  ret_from_fork+0x27/0x40
<6>[  553.953341] Sending NMI from CPU 1 to CPUs 0,2-7:
<4>[  553.953459] NMI backtrace for cpu 5 skipped: idling at pc 0xffffffff81911925
<4>[  553.953460] NMI backtrace for cpu 0 skipped: idling at pc 0xffffffff81911925
<4>[  553.953462] NMI backtrace for cpu 6 skipped: idling at pc 0xffffffff81911925
<4>[  553.953463] NMI backtrace for cpu 7 skipped: idling at pc 0xffffffff81911925
<4>[  553.953465] NMI backtrace for cpu 2 skipped: idling at pc 0xffffffff81911925
<4>[  553.953466] NMI backtrace for cpu 3 skipped: idling at pc 0xffffffff81911925
<4>[  553.954343] NMI backtrace for cpu 4
<4>[  553.954344] CPU: 4 PID: 224 Comm: kworker/4:2 Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3315+ #1
<4>[  553.954344] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  553.954344] Workqueue: events i915_hpd_poll_init_work [i915]
<4>[  553.954345] task: ffff88040a628040 task.stack: ffffc90000388000
<4>[  553.954345] RIP: 0010:io_serial_in+0x18/0x20
<4>[  553.954345] RSP: 0018:ffffc9000038bad8 EFLAGS: 00000002
<4>[  553.954346] RAX: 0000000080000000 RBX: ffffffff836212c0 RCX: 0000000000000000
<4>[  553.954346] RDX: 00000000000003fd RSI: 0000000000000005 RDI: ffffffff836212c0
<4>[  553.954346] RBP: ffffc9000038bad8 R08: 0000000000000001 R09: 0000000000000001
<4>[  553.954346] R10: ffffc9000038bac8 R11: ffffffff815b0141 R12: 0000000000002706
<4>[  553.954347] R13: 0000000000000020 R14: ffffffff82ca4f0d R15: ffffffff836212c0
<4>[  553.954347] FS:  0000000000000000(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  553.954347] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  553.954347] CR2: 00007f983b5c0220 CR3: 0000000003e0f006 CR4: 00000000001606e0
<4>[  553.954347] Call Trace:
<4>[  553.954348]  wait_for_xmitr+0x41/0xa0
<4>[  553.954348]  serial8250_console_putchar+0x1c/0x30
<4>[  553.954348]  ? wait_for_xmitr+0xa0/0xa0
<4>[  553.954348]  uart_console_write+0x30/0x70
<4>[  553.954348]  serial8250_console_write+0xd9/0x270
<4>[  553.954349]  ? vt_console_print+0x225/0x3b0
<4>[  553.954349]  ? msg_print_text+0x9d/0x100
<4>[  553.954349]  univ8250_console_write+0x26/0x30
<4>[  553.954349]  console_unlock+0x430/0x570
<4>[  553.954350]  vprintk_emit+0x254/0x3b0
<4>[  553.954350]  ? wake_up_q+0x59/0x80
<4>[  553.954350]  vprintk_default+0x1f/0x30
<4>[  553.954350]  vprintk_func+0x2c/0x90
<4>[  553.954351]  printk+0x43/0x4b
<4>[  553.954351]  ? drm_helper_hpd_irq_event+0xcc/0x110
<4>[  553.954351]  drm_printk+0x8e/0x90
<4>[  553.954351]  drm_helper_hpd_irq_event+0xcc/0x110
<4>[  553.954352]  i915_hpd_poll_init_work+0xc5/0x100 [i915]
<4>[  553.954352]  process_one_work+0x221/0x650
<4>[  553.954352]  worker_thread+0x4e/0x3c0
<4>[  553.954352]  kthread+0x114/0x150
<4>[  553.954352]  ? process_one_work+0x650/0x650
<4>[  553.954353]  ? kthread_create_on_node+0x40/0x40
<4>[  553.954353]  ret_from_fork+0x27/0x40
<4>[  553.954353] Code: 48 89 e5 d3 e6 48 63 f6 48 03 77 40 8b 06 5d c3 0f 1f 00 0f 1f 44 00 00 0f b6 8f d1 00 00 00 8b 57 38 55 48 89 e5 d3 e6 01 f2 ec <0f> b6 c0 5d c3 0f 1f 00 0f 1f 44 00 00 0f b6 8f d1 00 00 00 89 
<0>[  553.954371] Kernel panic - not syncing: hung_task: blocked tasks
<4>[  553.954372] CPU: 1 PID: 66 Comm: khungtaskd Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3315+ #1
<4>[  553.954373] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  553.954373] Call Trace:
<4>[  553.954374]  dump_stack+0x68/0x9f
<4>[  553.954375]  panic+0xd4/0x21d
<4>[  553.954377]  watchdog+0x460/0x610
<4>[  553.954378]  kthread+0x114/0x150
<4>[  553.954379]  ? reset_hung_task_detector+0x20/0x20
<4>[  553.954379]  ? kthread_create_on_node+0x40/0x40
<4>[  553.954380]  ret_from_fork+0x27/0x40
<0>[  553.956376] Kernel Offset: disabled
Comment 3 Daniel Vetter 2017-11-07 10:53:10 UTC
<tsa> danvet: hsw8 is fixed, but you told that it was seen on hsw2
<danvet> tsa, we split the bugs
<tsa> right. hsw8 should be fixed
<tsa> see run or two and archive the bug
Comment 4 Marta Löfstedt 2017-11-07 10:59:08 UTC
Set to resolved, need ~10 runs after CD_DRM_3217 to be able to clear it after HW change.
Comment 5 Marta Löfstedt 2017-11-07 10:59:36 UTC
(In reply to Marta Löfstedt from comment #4)
> Set to resolved, need ~10 runs after CD_DRM_3217 to be able to clear it
> after HW change.

CI_DRM_3317 that is!

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.