Bug 105054

Summary: [CI] igt@kms_vblank@pipe-b-ts-continuation-dpms-suspend - incomplete - INFO: task khugepaged:72 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 WORKSFORME 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 2018-02-12 08:48:00 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4235/shard-hsw3/igt@kms_vblank@pipe-b-ts-continuation-dpms-suspend.html

pstore:
<3>[18138.238145] INFO: task khugepaged:72 blocked for more than 60 seconds.
<3>[18138.238220]       Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<3>[18138.238271] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[18138.238333] khugepaged      D    0    72      2 0x80000000
<4>[18138.238347] Call Trace:
<4>[18138.238370]  ? __schedule+0x3c3/0xaf0
<4>[18138.238384]  ? _raw_spin_unlock_irq+0x24/0x50
<4>[18138.238394]  ? rwsem_down_read_failed+0x112/0x170
<4>[18138.238406]  schedule+0x37/0x90
<4>[18138.238415]  rwsem_down_read_failed+0x112/0x170
<4>[18138.238440]  ? call_rwsem_down_read_failed+0x14/0x30
<4>[18138.238449]  call_rwsem_down_read_failed+0x14/0x30
<4>[18138.238463]  ? khugepaged+0x2ef/0x2510
<4>[18138.238475]  down_read+0x44/0x60
<4>[18138.238484]  ? khugepaged+0x2ef/0x2510
<4>[18138.238493]  khugepaged+0x2ef/0x2510
<4>[18138.238532]  ? wait_woken+0x90/0x90
<4>[18138.238549]  kthread+0xfb/0x130
<4>[18138.238558]  ? collapse_shmem.isra.8+0xb90/0xb90
<4>[18138.238565]  ? _kthread_create_on_node+0x30/0x30
<4>[18138.238578]  ret_from_fork+0x3a/0x50
<4>[18138.238604] 
<4>[18138.238604] Showing all locks held in the system:
<4>[18138.238617] 2 locks held by khungtaskd/67:
<4>[18138.238629]  #0:  (rcu_read_lock){....}, at: [<00000000070efc1d>] watchdog+0x9b/0x5e0
<4>[18138.238661]  #1:  (tasklist_lock){.+.+}, at: [<00000000b8a414ca>] debug_show_all_locks+0x37/0x1a0
<4>[18138.238694] 1 lock held by khugepaged/72:
<4>[18138.238698]  #0:  (&mm->mmap_sem){++++}, at: [<000000004df9e3a9>] khugepaged+0x2ef/0x2510
<4>[18138.238737] 1 lock held by in:imklog/605:
<4>[18138.238742]  #0:  (&f->f_pos_lock){+.+.}, at: [<000000001305d183>] __fdget_pos+0x3a/0x50
<4>[18138.238775] 2 locks held by NetworkManager/667:
<4>[18138.238779]  #0:  (sb_writers#3){.+.+}, at: [<0000000090d45697>] mnt_want_write+0x1b/0x50
<4>[18138.238810]  #1:  (&type->i_mutex_dir_key/1){+.+.}, at: [<00000000de4db4cb>] do_unlinkat+0x107/0x2d0
<4>[18138.238845] 1 lock held by sshd/919:
<4>[18138.238849]  #0:  (&mm->mmap_sem){++++}, at: [<00000000ef3c0cff>] __do_page_fault+0x106/0x560
<4>[18138.238879] 1 lock held by java/971:
<4>[18138.238884]  #0:  (&mm->mmap_sem){++++}, at: [<00000000ef3c0cff>] __do_page_fault+0x106/0x560
<4>[18138.238911] 1 lock held by java/25174:
<4>[18138.238916]  #0:  (&mm->mmap_sem){++++}, at: [<00000000988e6036>] vm_mmap_pgoff+0x51/0xd0
<4>[18138.238944] 1 lock held by java/25712:
<4>[18138.238949]  #0:  (&mm->mmap_sem){++++}, at: [<00000000988e6036>] vm_mmap_pgoff+0x51/0xd0
<4>[18138.238979] 1 lock held by dmesg/24909:
<4>[18138.238984]  #0:  (&user->lock){+.+.}, at: [<00000000be4505c5>] devkmsg_read+0x35/0x2f0
<4>[18138.239091] 1 lock held by python3/25137:
<4>[18138.239100]  #0:  (&sbi->s_journal_flag_rwsem){.+.+}, at: [<0000000002f66b23>] do_writepages+0x1b/0x70
<4>[18138.239149] 6 locks held by kworker/u16:58/25875:
<4>[18138.239156]  #0:  ((wq_completion)"writeback"){+.+.}, at: [<00000000aecf3b95>] process_one_work+0x191/0x640
<4>[18138.239196]  #1:  ((work_completion)(&(&wb->dwork)->work)){+.+.}, at: [<00000000aecf3b95>] process_one_work+0x191/0x640
<4>[18138.239234]  #2:  (&type->s_umount_key#33){++++}, at: [<00000000a1cc8c81>] trylock_super+0x11/0x50
<4>[18138.239279]  #3:  (&sbi->s_journal_flag_rwsem){.+.+}, at: [<0000000002f66b23>] do_writepages+0x1b/0x70
<4>[18138.239316]  #4:  (jbd2_handle){++++}, at: [<00000000684be31f>] start_this_handle+0xff/0x440
<4>[18138.239345]  #5:  (&ei->i_data_sem){++++}, at: [<00000000ef905257>] ext4_map_blocks+0x11f/0x580
<4>[18138.239375] 
<4>[18138.239381] =============================================
<4>[18138.239381] 
<4>[18138.239388] NMI backtrace for cpu 0
<4>[18138.239396] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<4>[18138.239402] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[18138.239407] Call Trace:
<4>[18138.239418]  dump_stack+0x5f/0x86
<4>[18138.239428]  nmi_cpu_backtrace+0xb4/0xc0
<4>[18138.239442]  ? lapic_can_unplug_cpu+0x90/0x90
<4>[18138.239451]  nmi_trigger_cpumask_backtrace+0xb8/0xf0
<4>[18138.239463]  watchdog+0x43e/0x5e0
<4>[18138.239478]  kthread+0xfb/0x130
<4>[18138.239486]  ? reset_hung_task_detector+0x10/0x10
<4>[18138.239493]  ? _kthread_create_on_node+0x30/0x30
<4>[18138.239505]  ret_from_fork+0x3a/0x50
<6>[18138.239533] Sending NMI from CPU 0 to CPUs 1-7:
<4>[18138.239549] NMI backtrace for cpu 7
<4>[18138.239556] CPU: 7 PID: 217 Comm: systemd-journal Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<4>[18138.239558] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[18138.239569] RIP: 0010:__is_insn_slot_addr+0x50/0x120
<4>[18138.239572] RSP: 0018:ffffc90000387c28 EFLAGS: 00000002
<4>[18138.239577] RAX: ffffffff8224ec50 RBX: 00007f109414a947 RCX: 6da9f37000000000
<4>[18138.239580] RDX: ffffffff81138170 RSI: ffffffff820abf17 RDI: ffffffff820b9a65
<4>[18138.239582] RBP: ffffc90000387c38 R08: ffff88040b10d7f0 R09: 000000006fcf9f89
<4>[18138.239585] R10: ffffc90000387bb8 R11: ffffffff81138170 R12: 0000000000000000
<4>[18138.239588] R13: 0000000000000000 R14: ffffffff8224ebc0 R15: ffff88040e170a00
<4>[18138.239592] FS:  00007f1094e748c0(0000) GS:ffff88041fbc0000(0000) knlGS:0000000000000000
<4>[18138.239595] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[18138.239598] CR2: 000055b1b0b017e8 CR3: 000000040a2d8003 CR4: 00000000001606e0
<4>[18138.239599] Call Trace:
<4>[18138.239607]  kernel_text_address+0xbe/0xd0
<4>[18138.239617]  ? unwind_next_frame+0x42f/0x6b0
<4>[18138.239621]  __kernel_text_address+0x9/0x30
<4>[18138.239628]  unwind_get_return_address+0x16/0x30
<4>[18138.239634]  __save_stack_trace+0x7e/0xd0
<4>[18138.239644]  ? prepare_creds+0x1b/0xb0
<4>[18138.239649]  ? prepare_creds+0x1b/0xb0
<4>[18138.239654]  set_track+0x5c/0x120
<4>[18138.239661]  alloc_debug_processing+0x156/0x1a0
<4>[18138.239667]  ___slab_alloc.constprop.30+0x3a8/0x3d0
<4>[18138.239672]  ? prepare_creds+0x1b/0xb0
<4>[18138.239681]  ? seccomp_run_filters+0x3d/0x120
<4>[18138.239690]  ? lock_acquire+0xaf/0x200
<4>[18138.239696]  ? prepare_creds+0x1b/0xb0
<4>[18138.239702]  ? __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[18138.239707]  __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[18138.239713]  ? prepare_creds+0x1b/0xb0
<4>[18138.239717]  kmem_cache_alloc+0x21a/0x2b0
<4>[18138.239724]  prepare_creds+0x1b/0xb0
<4>[18138.239733]  SyS_faccessat+0x33/0x200
<4>[18138.239741]  do_syscall_64+0x59/0x1a0
<4>[18138.239749]  entry_SYSCALL64_slow_path+0x25/0x25
<4>[18138.239752] RIP: 0033:0x7f109414a947
<4>[18138.239755] RSP: 002b:00007ffd21840ef8 EFLAGS: 00000246 ORIG_RAX: 0000000000000015
<4>[18138.239760] RAX: ffffffffffffffda RBX: 00007ffd21843e00 RCX: 00007f109414a947
<4>[18138.239762] RDX: 00007f1094bba3e0 RSI: 0000000000000000 RDI: 000055a9fae9b881
<4>[18138.239765] RBP: 00007ffd21840f30 R08: 0000000000002000 R09: 0000000000000000
<4>[18138.239767] R10: 0000000000000080 R11: 0000000000000246 R12: 0000000000000000
<4>[18138.239770] R13: 0000000000000000 R14: 00007ffd21843e00 R15: 0000000000000009
<4>[18138.239776] Code: 00 48 c7 c7 a0 64 24 82 e8 2e 11 fa ff e8 b9 f2 fb ff 85 c0 5a 74 0d 80 3d 2a 7d 1c 01 00 0f 84 9d 00 00 00 49 8b 86 90 00 00 00 <49> 8d be 90 00 00 00 48 39 f8 74 1d 48 8b 50 10 48 39 da 77 0c 
<4>[18138.239855] NMI backtrace for cpu 6
<4>[18138.239862] CPU: 6 PID: 605 Comm: in:imklog Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<4>[18138.239864] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[18138.239873] RIP: 0010:check_chain_key+0x1f/0x140
<4>[18138.239876] RSP: 0018:ffffc9000090fd48 EFLAGS: 00000046
<4>[18138.239881] RAX: 0000000000000000 RBX: ffff8804071d0040 RCX: 0000000000000000
<4>[18138.239884] RDX: 0000000000000001 RSI: 0000000000000002 RDI: ffff8804071d0040
<4>[18138.239886] RBP: ffffffff82255a40 R08: 0000000000000001 R09: 0000000000000001
<4>[18138.239889] R10: 0000000000000000 R11: 0000000000000001 R12: ffff8804071d0040
<4>[18138.239891] R13: 0000000000000282 R14: 0000000000000001 R15: 00007fd343724ab1
<4>[18138.239895] FS:  00007fd343744700(0000) GS:ffff88041fb80000(0000) knlGS:0000000000000000
<4>[18138.239898] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[18138.239901] CR2: 000055b1b0b017e8 CR3: 0000000409b8c002 CR4: 00000000001606e0
<4>[18138.239903] Call Trace:
<4>[18138.239915]  ? fs_reclaim_acquire+0x10/0x10
<4>[18138.239921]  lock_release+0x11f/0x300
<4>[18138.239928]  ? do_syslog+0x2a4/0x4f0
<4>[18138.239933]  kmem_cache_alloc_trace+0x2d/0x2b0
<4>[18138.239938]  do_syslog+0x2a4/0x4f0
<4>[18138.239947]  kmsg_read+0x39/0x50
<4>[18138.239953]  proc_reg_read+0x38/0x60
<4>[18138.239959]  __vfs_read+0x1e/0x120
<4>[18138.239966]  vfs_read+0x9e/0x150
<4>[18138.239972]  SyS_read+0x40/0xa0
<4>[18138.239980]  entry_SYSCALL_64_fastpath+0x22/0x8f
<4>[18138.239984] RIP: 0033:0x7fd345b906ed
<4>[18138.239986] RSP: 002b:00007fd343723580 EFLAGS: 00000293
<4>[18138.239993] Code: c0 5b c3 66 0f 1f 84 00 00 00 00 00 41 55 41 54 49 89 fc 55 53 8b 97 a8 08 00 00 85 d2 0f 84 1f 01 00 00 48 83 bf b0 08 00 00 00 <4c> 8d 87 b0 08 00 00 0f 85 d8 00 00 00 31 db 31 ed 31 ff eb 25 
<4>[18138.240081] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120
<4>[18138.240093] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120
<4>[18138.240099] NMI backtrace for cpu 1
<4>[18138.240106] CPU: 1 PID: 606 Comm: rs:main Q:Reg Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<4>[18138.240109] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[18138.240117] RIP: 0010:deactivate_slab.isra.23+0x1c3/0x880
<4>[18138.240121] RSP: 0018:ffffc900008a7ad0 EFLAGS: 00000086
<4>[18138.240126] RAX: 00000000000001c8 RBX: ffff880401a3dec0 RCX: 0000000000000001
<4>[18138.240129] RDX: ffff880401a3f3c0 RSI: ffff880401a3dec0 RDI: 00000000ffffffff
<4>[18138.240132] RBP: ffffc900008a7be0 R08: ffff88041fa665b0 R09: ffff880401a3c800
<4>[18138.240134] R10: ffffc900008a7c00 R11: ffffffff81138170 R12: ffffea0010068e00
<4>[18138.240137] R13: 0000000180240012 R14: ffff880401a3bbc0 R15: ffff88040e1720c0
<4>[18138.240141] FS:  00007fd342f43700(0000) GS:ffff88041fa40000(0000) knlGS:0000000000000000
<4>[18138.240144] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[18138.240147] CR2: 000055b1b0ad3f68 CR3: 0000000409b8c005 CR4: 00000000001606e0
<4>[18138.240149] Call Trace:
<4>[18138.240155]  ? kernel_text_address+0xbe/0xd0
<4>[18138.240163]  ? unwind_next_frame+0x42f/0x6b0
<4>[18138.240168]  ? __kernel_text_address+0x9/0x30
<4>[18138.240178]  ? get_empty_filp+0x53/0x180
<4>[18138.240186]  ? get_empty_filp+0x53/0x180
<4>[18138.240192]  ? set_track+0x85/0x120
<4>[18138.240201]  ? init_object+0x6e/0x80
<4>[18138.240209]  ? ___slab_alloc.constprop.30+0x152/0x3d0
<4>[18138.240216]  ___slab_alloc.constprop.30+0x152/0x3d0
<4>[18138.240223]  ? get_empty_filp+0x53/0x180
<4>[18138.240231]  ? _raw_spin_unlock+0x29/0x40
<4>[18138.240239]  ? deactivate_slab.isra.23+0x856/0x880
<4>[18138.240248]  ? lock_acquire+0xaf/0x200
<4>[18138.240255]  ? get_empty_filp+0x53/0x180
<4>[18138.240262]  ? __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[18138.240270]  __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[18138.240277]  ? get_empty_filp+0x53/0x180
<4>[18138.240284]  kmem_cache_alloc+0x21a/0x2b0
<4>[18138.240291]  get_empty_filp+0x53/0x180
<4>[18138.240299]  path_openat+0x25/0x9d0
<4>[18138.240307]  ? futex_wake+0x80/0x140
<4>[18138.240315]  do_filp_open+0x85/0xf0
<4>[18138.240325]  ? __alloc_fd+0xe9/0x200
<4>[18138.240340]  ? do_sys_open+0x12b/0x1f0
<4>[18138.240348]  do_sys_open+0x12b/0x1f0
<4>[18138.240360]  entry_SYSCALL_64_fastpath+0x22/0x8f
<4>[18138.240367] RIP: 0033:0x7fd345b90d8d
<4>[18138.240372] RSP: 002b:00007fd342f427c0 EFLAGS: 00000293
<4>[18138.240381] Code: 65 8b 05 41 8b e3 7e 85 c0 74 60 49 63 47 20 48 8b b5 40 ff ff ff 4d 8b 74 24 10 48 8b 14 06 48 85 d2 74 55 48 8b 9d 40 ff ff ff <48> 89 95 40 ff ff ff e9 d6 fe ff ff 48 89 95 48 ff ff ff bf 01 
<4>[18138.240554] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120
<4>[18138.240565] NMI backtrace for cpu 5 skipped: idling at intel_idle+0x6f/0x120
<6>[18138.240711] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.009 msecs
<0>[18138.241556] Kernel panic - not syncing: hung_task: blocked tasks
<4>[18138.241610] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G     U  W        4.15.0-CI-CI_DRM_3751+ #1
<4>[18138.241677] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[18138.241733] Call Trace:
<4>[18138.241763]  dump_stack+0x5f/0x86
<4>[18138.241798]  panic+0xcf/0x20d
<4>[18138.241843]  watchdog+0x44a/0x5e0
<4>[18138.241881]  kthread+0xfb/0x130
<4>[18138.241913]  ? reset_hung_task_detector+0x10/0x10
<4>[18138.241952]  ? _kthread_create_on_node+0x30/0x30
<4>[18138.241997]  ret_from_fork+0x3a/0x50
<0>[18138.242101] Dumping ftrace buffer:
<0>[18138.242234]    (ftrace buffer empty)
<0>[18138.242269] Kernel Offset: disabled

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.