Bug 104874

Summary: [CI] igt@* - incomplete - INFO: task *:* 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: XOrg git   
Hardware: Other   
OS: All   
See Also: https://bugs.freedesktop.org/show_bug.cgi?id=105392
Whiteboard: ReadyForDev
i915 platform: HSW i915 features:

Description Marta Löfstedt 2018-01-31 08:17:44 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3701/shard-hsw4/igt@gem_exec_suspend@basic-s4-devices.html

<3>[  431.276629] INFO: task dmesg:1072 blocked for more than 60 seconds.
<3>[  431.276701]       Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<3>[  431.276753] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[  431.276814] dmesg           D    0  1072    995 0x00000000
<4>[  431.276828] Call Trace:
<4>[  431.276853]  ? __schedule+0x3c3/0xaf0
<4>[  431.276871]  ? bit_wait+0x50/0x50
<4>[  431.276884]  schedule+0x37/0x90
<4>[  431.276896]  io_schedule+0xd/0x30
<4>[  431.276906]  bit_wait_io+0x8/0x50
<4>[  431.276916]  __wait_on_bit+0x4e/0x80
<4>[  431.276931]  out_of_line_wait_on_bit+0x78/0x80
<4>[  431.276943]  ? bit_waitqueue+0x30/0x30
<4>[  431.276956]  do_get_write_access+0x1f4/0x660
<4>[  431.276975]  ? ext4_dirty_inode+0x3e/0x60
<4>[  431.276984]  jbd2_journal_get_write_access+0x27/0x50
<4>[  431.276996]  __ext4_journal_get_write_access+0x5e/0xb0
<4>[  431.277009]  ext4_reserve_inode_write+0x88/0xb0
<4>[  431.277021]  ext4_mark_inode_dirty+0x63/0x270
<4>[  431.277031]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[  431.277047]  ext4_dirty_inode+0x3e/0x60
<4>[  431.277058]  __mark_inode_dirty+0x67/0x690
<4>[  431.277073]  generic_update_time+0x73/0xc0
<4>[  431.277082]  ? current_time+0x2d/0x60
<4>[  431.277094]  file_update_time+0x90/0xe0
<4>[  431.277111]  __generic_file_write_iter+0x94/0x1b0
<4>[  431.277129]  ext4_file_write_iter+0x10f/0x3a0
<4>[  431.277144]  ? lock_acquire+0xaf/0x200
<4>[  431.277160]  __vfs_write+0xc5/0x130
<4>[  431.277180]  vfs_write+0xbd/0x1b0
<4>[  431.277192]  SyS_write+0x40/0xa0
<4>[  431.277207]  entry_SYSCALL_64_fastpath+0x22/0x8f
<4>[  431.277215] RIP: 0033:0x7f1ea54f88f0
<4>[  431.277221] RSP: 002b:00007ffe26a7fc78 EFLAGS: 00000246
<4>[  431.277247] 
<4>[  431.277247] Showing all locks held in the system:
<4>[  431.277269] 2 locks held by khungtaskd/67:
<4>[  431.277280]  #0:  (rcu_read_lock){....}, at: [<00000000319d6f30>] watchdog+0x9b/0x5e0
<4>[  431.277312]  #1:  (tasklist_lock){.+.+}, at: [<0000000007d1d642>] debug_show_all_locks+0x37/0x1a0
<4>[  431.277353] 1 lock held by systemd-udevd/250:
<4>[  431.277357]  #0:  (&type->i_mutex_dir_key){++++}, at: [<0000000077ad1826>] lookup_slow+0xaf/0x1b0
<4>[  431.277393] 1 lock held by in:imklog/575:
<4>[  431.277398]  #0:  (&f->f_pos_lock){+.+.}, at: [<00000000b20b5414>] __fdget_pos+0x3a/0x50
<4>[  431.277431] 2 locks held by NetworkManager/665:
<4>[  431.277436]  #0:  (sb_writers#3){.+.+}, at: [<00000000a50e88f8>] mnt_want_write+0x1b/0x50
<4>[  431.277466]  #1:  (&type->i_mutex_dir_key/1){+.+.}, at: [<00000000e3fb6276>] do_unlinkat+0x107/0x2d0
<4>[  431.277575] 3 locks held by dmesg/1072:
<4>[  431.277580]  #0:  (sb_writers#3){.+.+}, at: [<000000004d6f3c87>] vfs_write+0x158/0x1b0
<4>[  431.277619]  #1:  (&sb->s_type->i_mutex_key#14){+.+.}, at: [<00000000d9faa4ef>] ext4_file_write_iter+0x64/0x3a0
<4>[  431.277668]  #2:  (jbd2_handle){++++}, at: [<000000003cfde8e9>] start_this_handle+0xff/0x440
<4>[  431.277709] 3 locks held by python3/1301:
<4>[  431.277715]  #0:  (sb_writers#3){.+.+}, at: [<00000000a50e88f8>] mnt_want_write+0x1b/0x50
<4>[  431.277758]  #1:  (&type->i_mutex_dir_key){++++}, at: [<000000002af914c9>] path_openat+0x440/0x9d0
<4>[  431.277794]  #2:  (jbd2_handle){++++}, at: [<000000003cfde8e9>] start_this_handle+0xff/0x440
<4>[  431.277847] 4 locks held by kworker/u16:60/3002:
<4>[  431.277852]  #0:  ((wq_completion)"writeback"){+.+.}, at: [<00000000d741bf6b>] process_one_work+0x191/0x640
<4>[  431.277882]  #1:  ((work_completion)(&(&wb->dwork)->work)){+.+.}, at: [<00000000d741bf6b>] process_one_work+0x191/0x640
<4>[  431.277909]  #2:  (&type->s_umount_key#33){++++}, at: [<000000000bde5a54>] trylock_super+0x11/0x50
<4>[  431.277941]  #3:  (&sbi->s_journal_flag_rwsem){.+.+}, at: [<000000007cf99b19>] do_writepages+0x1b/0x70
<4>[  431.277973] 2 locks held by cron/3012:
<4>[  431.277978]  #0:  (sb_writers#3){.+.+}, at: [<00000000a50e88f8>] mnt_want_write+0x1b/0x50
<4>[  431.278007]  #1:  (&type->i_mutex_dir_key){++++}, at: [<000000002af914c9>] path_openat+0x440/0x9d0
<4>[  431.278034] 
<4>[  431.278040] =============================================
<4>[  431.278040] 
<4>[  431.278047] NMI backtrace for cpu 5
<4>[  431.278058] CPU: 5 PID: 67 Comm: khungtaskd Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<4>[  431.278067] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  431.278074] Call Trace:
<4>[  431.278089]  dump_stack+0x5f/0x86
<4>[  431.278104]  nmi_cpu_backtrace+0xb4/0xc0
<4>[  431.278121]  ? lapic_can_unplug_cpu+0x90/0x90
<4>[  431.278134]  nmi_trigger_cpumask_backtrace+0xb8/0xf0
<4>[  431.278148]  watchdog+0x43e/0x5e0
<4>[  431.278165]  kthread+0xfb/0x130
<4>[  431.278173]  ? reset_hung_task_detector+0x10/0x10
<4>[  431.278180]  ? _kthread_create_on_node+0x30/0x30
<4>[  431.278193]  ret_from_fork+0x3a/0x50
<6>[  431.278223] Sending NMI from CPU 5 to CPUs 0-4,6-7:
<4>[  431.278240] NMI backtrace for cpu 2
<4>[  431.278247] CPU: 2 PID: 228 Comm: systemd-journal Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<4>[  431.278250] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  431.278262] RIP: 0010:debug_check_no_locks_freed+0xa9/0x140
<4>[  431.278265] RSP: 0018:ffffc900003bfe88 EFLAGS: 00000002
<4>[  431.278270] RAX: 0000000000000000 RBX: ffff8804057a9200 RCX: 0000000000d20c83
<4>[  431.278272] RDX: 0000000000000000 RSI: ffffffff821087b1 RDI: ffffffff811deecb
<4>[  431.278275] RBP: ffff8804057a9200 R08: 0000000000000000 R09: 0000000000000001
<4>[  431.278277] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000001000
<4>[  431.278280] R13: 0000000000000002 R14: ffff88040c9c27c0 R15: 0000559475442bf0
<4>[  431.278284] FS:  00007fc2694428c0(0000) GS:ffff88041fa80000(0000) knlGS:0000000000000000
<4>[  431.278286] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  431.278289] CR2: 00007fc2640fa008 CR3: 00000004099c8005 CR4: 00000000001606e0
<4>[  431.278291] Call Trace:
<4>[  431.278303]  ? do_sys_open+0x197/0x1f0
<4>[  431.278309]  kmem_cache_free+0x8b/0x320
<4>[  431.278317]  do_sys_open+0x197/0x1f0
<4>[  431.278326]  do_syscall_64+0x59/0x1a0
<4>[  431.278333]  entry_SYSCALL64_slow_path+0x25/0x25
<4>[  431.278337] RIP: 0033:0x7fc2689f7d70
<4>[  431.278339] RSP: 002b:00007fff979ff788 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
<4>[  431.278344] RAX: ffffffffffffffda RBX: 00007fff979ffa90 RCX: 00007fc2689f7d70
<4>[  431.278346] RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 0000559475442dd0
<4>[  431.278349] RBP: 000000000000000d R08: 00000000000001c0 R09: 00000000ffffffff
<4>[  431.278351] R10: 00007fc2689e1b58 R11: 0000000000000246 R12: 00000000ffffffff
<4>[  431.278354] R13: 000055947542c040 R14: 00007fff979ffa50 R15: 0000559475442bf0
<4>[  431.278361] Code: 85 c0 74 34 41 f7 c5 00 02 00 00 74 16 48 8b 7c 24 28 e8 1b fc ff ff 41 55 9d 5b 5d 41 5c 41 5d 41 5e c3 41 55 9d 48 8b 7c 24 28 <5b> 5d 41 5c 41 5d 41 5e e9 0a cc ff ff 48 c7 c7 44 6e 07 82 e8 
<4>[  431.278445] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120
<4>[  431.278451] NMI backtrace for cpu 3
<4>[  431.278459] CPU: 3 PID: 576 Comm: rs:main Q:Reg Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<4>[  431.278461] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  431.278471] RIP: 0010:lock_release+0x134/0x300
<4>[  431.278474] RSP: 0018:ffffc900004df9c0 EFLAGS: 00000046
<4>[  431.278479] RAX: ffff880406f0cf40 RBX: ffff880406f0cf40 RCX: 1028129d00000000
<4>[  431.278481] RDX: 0000000000000003 RSI: 000000004e9f6afb RDI: 0000000000000000
<4>[  431.278484] RBP: ffffffff822464a0 R08: ffff880406f0d840 R09: 000000004fa73c86
<4>[  431.278487] R10: 0000000000000000 R11: ffffffff81138170 R12: ffffffff811381fd
<4>[  431.278489] R13: 0000000000000082 R14: 0000000000000003 R15: ffff88040ae420c0
<4>[  431.278495] FS:  00007f359b41e700(0000) GS:ffff88041fac0000(0000) knlGS:0000000000000000
<4>[  431.278499] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  431.278503] CR2: 00007fc3d5ad8ed8 CR3: 0000000409a5c001 CR4: 00000000001606e0
<4>[  431.278505] Call Trace:
<4>[  431.278517]  __is_insn_slot_addr+0xaa/0x120
<4>[  431.278524]  kernel_text_address+0xab/0xd0
<4>[  431.278534]  ? unwind_next_frame+0x42f/0x6b0
<4>[  431.278539]  __kernel_text_address+0x9/0x30
<4>[  431.278546]  unwind_get_return_address+0x16/0x30
<4>[  431.278552]  __save_stack_trace+0x7e/0xd0
<4>[  431.278563]  ? jbd2__journal_start+0x69/0x2b0
<4>[  431.278569]  ? jbd2__journal_start+0x69/0x2b0
<4>[  431.278574]  set_track+0x5c/0x120
<4>[  431.278581]  alloc_debug_processing+0x156/0x1a0
<4>[  431.278588]  ___slab_alloc.constprop.30+0x3a8/0x3d0
<4>[  431.278594]  ? jbd2__journal_start+0x69/0x2b0
<4>[  431.278602]  ? lock_acquire+0xaf/0x200
<4>[  431.278610]  ? __lock_acquire+0x4ab/0x1b60
<4>[  431.278617]  ? jbd2__journal_start+0x69/0x2b0
<4>[  431.278623]  ? __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[  431.278627]  __slab_alloc.isra.24.constprop.29+0x3d/0x70
<4>[  431.278633]  ? jbd2__journal_start+0x69/0x2b0
<4>[  431.278638]  kmem_cache_alloc+0x21a/0x2b0
<4>[  431.278645]  jbd2__journal_start+0x69/0x2b0
<4>[  431.278653]  ext4_dirty_inode+0x28/0x60
<4>[  431.278659]  __mark_inode_dirty+0x67/0x690
<4>[  431.278667]  generic_update_time+0x73/0xc0
<4>[  431.278672]  ? current_time+0x2d/0x60
<4>[  431.278678]  file_update_time+0x90/0xe0
<4>[  431.278687]  __generic_file_write_iter+0x94/0x1b0
<4>[  431.278696]  ext4_file_write_iter+0x10f/0x3a0
<4>[  431.278703]  ? lock_acquire+0xaf/0x200
<4>[  431.278709]  __vfs_write+0xc5/0x130
<4>[  431.278717]  vfs_write+0xbd/0x1b0
<4>[  431.278722]  SyS_write+0x40/0xa0
<4>[  431.278730]  entry_SYSCALL_64_fastpath+0x22/0x8f
<4>[  431.278737] RIP: 0033:0x7f359e06b68d
<4>[  431.278740] RSP: 002b:00007f359b41d5c0 EFLAGS: 00000293
<4>[  431.278747] Code: 85 d2 0f 84 f4 00 00 00 65 48 8b 3c 25 80 4e 01 00 e8 a1 a4 ff ff 65 48 8b 04 25 80 4e 01 00 c7 80 ac 08 00 00 00 00 00 00 41 55 <9d> 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e f3 c3 65 8b 05 16 5b f3 
<4>[  431.278826] NMI backtrace for cpu 4
<4>[  431.278832] CPU: 4 PID: 575 Comm: in:imklog Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<4>[  431.278834] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  431.278843] RIP: 0010:preempt_count_sub+0x0/0x90
<4>[  431.278846] RSP: 0018:ffffc900005cfd30 EFLAGS: 00000246
<4>[  431.278851] RAX: ffff880406f08040 RBX: 0000000000000246 RCX: 0000000000000006
<4>[  431.278853] RDX: 0000000000000ec4 RSI: ffffffff821087b1 RDI: 0000000000000001
<4>[  431.278856] RBP: ffffffff8379cd88 R08: ffff880406f088f0 R09: 000000003638e619
<4>[  431.278859] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8803f85a13f8
<4>[  431.278864] R13: ffffffff8379cd80 R14: 0000000000000001 R15: ffffffff8379cd88
<4>[  431.278868] FS:  00007f359bc1f700(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  431.278872] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  431.278876] CR2: 00007fc3d5ade080 CR3: 0000000409a5c001 CR4: 00000000001606e0
<4>[  431.278879] Call Trace:
<4>[  431.278887]  _raw_spin_unlock_irqrestore+0x39/0x60
<4>[  431.278896]  debug_check_no_obj_freed+0x11f/0x230
<4>[  431.278905]  ? mark_held_locks+0x64/0x90
<4>[  431.278911]  ? do_syslog+0x450/0x4f0
<4>[  431.278917]  kfree+0x1bd/0x2d0
<4>[  431.278923]  do_syslog+0x450/0x4f0
<4>[  431.278933]  kmsg_read+0x39/0x50
<4>[  431.278941]  proc_reg_read+0x38/0x60
<4>[  431.278946]  __vfs_read+0x1e/0x120
<4>[  431.278954]  vfs_read+0x9e/0x150
<4>[  431.278960]  SyS_read+0x40/0xa0
<4>[  431.278968]  entry_SYSCALL_64_fastpath+0x22/0x8f
<4>[  431.278972] RIP: 0033:0x7f359e06b6ed
<4>[  431.278975] RSP: 002b:00007f359bbfe580 EFLAGS: 00000293
<4>[  431.278983] Code: 80 02 00 00 48 89 83 88 02 00 00 8b 05 9e b2 19 01 89 83 a0 02 00 00 31 c0 66 89 83 a4 02 00 00 5b 5d c3 0f 1f 84 00 00 00 00 00 <8b> 0d 72 56 5c 02 85 c9 75 1b 65 8b 15 7f d5 f6 7e 89 d1 81 e1 
<4>[  431.279071] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120
<4>[  431.279082] NMI backtrace for cpu 0 skipped: idling at intel_idle+0x6f/0x120
<4>[  431.279092] NMI backtrace for cpu 1 skipped: idling at intel_idle+0x6f/0x120
<0>[  431.279248] Kernel panic - not syncing: hung_task: blocked tasks
<4>[  431.279304] CPU: 5 PID: 67 Comm: khungtaskd Tainted: G     U  W        4.15.0-CI-CI_DRM_3701+ #1
<4>[  431.279373] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  431.279433] Call Trace:
<4>[  431.279466]  dump_stack+0x5f/0x86
<4>[  431.279503]  panic+0xcf/0x20d
<4>[  431.279549]  watchdog+0x44a/0x5e0
<4>[  431.279594]  kthread+0xfb/0x130
<4>[  431.279629]  ? reset_hung_task_detector+0x10/0x10
<4>[  431.279671]  ? _kthread_create_on_node+0x30/0x30
<4>[  431.279717]  ret_from_fork+0x3a/0x50
<0>[  431.279798] Dumping ftrace buffer:
<0>[  431.279939]    (ftrace buffer empty)
Comment 1 Marta Löfstedt 2018-03-08 07:01:58 UTC 
*** Bug 105392 has been marked as a duplicate of this bug. ***
Comment 2 Marta Löfstedt 2018-03-08 07:02:14 UTC 
*** Bug 105087 has been marked as a duplicate of this bug. ***
Comment 4 Marta Löfstedt 2018-03-28 09:13:42 UTC 
I will close this because the original issue hasn't reappeared on any of the tests.

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.