| Summary: | [CI] igt@gem_tiled_swapping@non-threaded - cause incompletes on following tests | ||
|---|---|---|---|
| Product: | DRI | Reporter: | Marta Löfstedt <marta.lofstedt> |
| Component: | DRM/Intel | Assignee: | Marta Löfstedt <marta.lofstedt> |
| 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, SNB | i915 features: | GEM/Other |
|
Description
Marta Löfstedt
2017-12-12 07:39:33 UTC
Also see bug 104009 and bug 103525 Note bug 103525 has the most likely clue: <14>[ 495.250162] [IGT] gem_tiled_swapping: executing <3>[ 615.691911] INFO: task gem_tiled_swapp:6686 blocked for more than 60 seconds. <3>[ 615.691963] Tainted: G U 4.14.0-rc6-CI-CI_DRM_3294+ #1 <3>[ 615.691996] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 615.692033] gem_tiled_swapp D 0 6686 3317 0x00000000 <4>[ 615.692042] Call Trace: <4>[ 615.692054] __schedule+0x3c3/0xaf0 <4>[ 615.692064] schedule+0x40/0x90 <4>[ 615.692071] io_schedule+0x16/0x40 <4>[ 615.692077] __lock_page+0x10d/0x140 <4>[ 615.692085] ? add_to_page_cache_lru+0xd0/0xd0 <4>[ 615.692094] deferred_split_scan+0x25e/0x2b0 <4>[ 615.692104] shrink_slab.part.17+0x202/0x5e0 <4>[ 615.692118] shrink_node+0x2f7/0x300 <4>[ 615.692129] do_try_to_free_pages+0xc6/0x310 <4>[ 615.692138] try_to_free_pages+0x122/0x330 <4>[ 615.692147] __alloc_pages_nodemask+0x6f9/0x1380 <4>[ 615.692167] ksm_might_need_to_copy+0x84/0x210 <4>[ 615.692176] do_swap_page+0x1c0/0x7f0 <4>[ 615.692185] __handle_mm_fault+0x7ef/0xed0 <4>[ 615.692198] handle_mm_fault+0x156/0x300 <4>[ 615.692204] __get_user_pages+0x10a/0x5c0 <4>[ 615.692210] ? lock_acquire+0xb0/0x200 <4>[ 615.692221] populate_vma_page_range+0x71/0x80 <4>[ 615.692226] __mm_populate+0x97/0x110 <4>[ 615.692233] do_mlock+0xf5/0x230 <4>[ 615.692240] SyS_mlock+0x13/0x20 <4>[ 615.692247] entry_SYSCALL_64_fastpath+0x1c/0xb1 <4>[ 615.692251] RIP: 0033:0x7fdabda9cdc7 <4>[ 615.692254] RSP: 002b:00007ffee3c75e28 EFLAGS: 00000246 ORIG_RAX: 0000000000000095 <4>[ 615.692261] RAX: ffffffffffffffda RBX: ffffffff81491ef3 RCX: 00007fdabda9cdc7 <4>[ 615.692265] RDX: 0000000000000000 RSI: 00000003a9100000 RDI: 00007fd71367c010 <4>[ 615.692268] RBP: ffffc90000707f88 R08: 0000561cce907480 R09: 0000000000000000 <4>[ 615.692271] R10: 0000000000000073 R11: 0000000000000246 R12: 0000000000000000 <4>[ 615.692275] R13: 00007ffee3c75fc0 R14: 0000000000000003 R15: 0000000000001000 <4>[ 615.692282] ? __this_cpu_preempt_check+0x13/0x20 <4>[ 615.692290] <4>[ 615.692290] Showing all locks held in the system: <4>[ 615.692305] 2 locks held by khungtaskd/66: <4>[ 615.692312] #0: (rcu_read_lock){....}, at: [<ffffffff8113f083>] watchdog+0xa3/0x610 <4>[ 615.692331] #1: (tasklist_lock){.+.+}, at: [<ffffffff810d945d>] debug_show_all_locks+0x3d/0x1a0 <4>[ 615.692358] 1 lock held by in:imklog/538: <4>[ 615.692361] #0: (&f->f_pos_lock){+.+.}, at: [<ffffffff81243233>] __fdget_pos+0x43/0x50 <4>[ 615.692390] 1 lock held by dmesg/3085: <4>[ 615.692393] #0: (&user->lock){+.+.}, at: [<ffffffff810eefce>] devkmsg_read+0x3e/0x300 <4>[ 615.692419] 2 locks held by gem_tiled_swapp/6686: <4>[ 615.692422] #0: (&mm->mmap_sem){++++}, at: [<ffffffff811cbb73>] __mm_populate+0xc3/0x110 <4>[ 615.692438] #1: (shrinker_rwsem){++++}, at: [<ffffffff811a8dff>] shrink_slab.part.17+0x4f/0x5e0 <4>[ 615.692456] <4>[ 615.692459] ============================================= <4>[ 615.692459] <4>[ 615.692463] NMI backtrace for cpu 5 <4>[ 615.692468] CPU: 5 PID: 66 Comm: khungtaskd Tainted: G U 4.14.0-rc6-CI-CI_DRM_3294+ #1 <4>[ 615.692471] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 615.692474] Call Trace: <4>[ 615.692481] dump_stack+0x68/0x9f <4>[ 615.692487] nmi_cpu_backtrace+0xbe/0xc0 <4>[ 615.692495] ? irq_force_complete_move+0xe0/0xe0 <4>[ 615.692499] nmi_trigger_cpumask_backtrace+0xc0/0x100 <4>[ 615.692506] arch_trigger_cpumask_backtrace+0x19/0x20 <4>[ 615.692510] watchdog+0x454/0x610 <4>[ 615.692517] kthread+0x114/0x150 <4>[ 615.692521] ? reset_hung_task_detector+0x20/0x20 <4>[ 615.692525] ? kthread_create_on_node+0x40/0x40 <4>[ 615.692532] ret_from_fork+0x27/0x40 <6>[ 615.692544] Sending NMI from CPU 5 to CPUs 0-4,6-7: <4>[ 615.692557] NMI backtrace for cpu 1 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692574] NMI backtrace for cpu 6 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692578] NMI backtrace for cpu 0 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692582] NMI backtrace for cpu 2 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692586] NMI backtrace for cpu 4 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692591] NMI backtrace for cpu 7 skipped: idling at pc 0xffffffff819106fe <4>[ 615.692595] NMI backtrace for cpu 3 skipped: idling at pc 0xffffffff819106fe <0>[ 615.693737] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 615.693795] CPU: 5 PID: 66 Comm: khungtaskd Tainted: G U 4.14.0-rc6-CI-CI_DRM_3294+ #1 <4>[ 615.693872] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 615.693936] Call Trace: <4>[ 615.693966] dump_stack+0x68/0x9f <4>[ 615.694002] panic+0xd4/0x21d <4>[ 615.694041] watchdog+0x460/0x610 <4>[ 615.694079] kthread+0x114/0x150 <4>[ 615.694111] ? reset_hung_task_detector+0x20/0x20 <4>[ 615.694155] ? kthread_create_on_node+0x40/0x40 <4>[ 615.694200] ret_from_fork+0x27/0x40 <0>[ 615.694959] Kernel Offset: disabled https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3503/shard-hsw8/igt@gem_pwrite@huge-gtt-backwards.html Again run.log: running: igt/gem_tiled_swapping/non-threaded [45/77] skip: 18, pass: 27 / FATAL: command execution failed java.io.EOFException but igt@gem_pwrite@huge-gtt-backwards is last in results. from dmesg: <7>[ 302.516333] [IGT] gem_tiled_swapping: executing <6>[ 302.540194] gem_tiled_swapp (1691): drop_caches: 4 <7>[ 304.318540] [IGT] gem_tiled_swapping: starting subtest non-threaded <7>[ 328.341323] [IGT] gem_tiled_swapping: exiting, ret=0 ... see nothing special last dmesg: <7>[ 330.450679] [IGT] gem_exec_reloc: exiting, ret=0 <7>[ 330.589845] [IGT] gem_pwrite: executing <7>[ 330.605445] [IGT] gem_pwrite: starting subtest huge-gtt-backwards https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4063/shard-hsw7/igt@gem_tiled_pread_basic.html from pstore: <14>[ 56.825306] [IGT] gem_tiled_swapping: exiting, ret=0 <14>[ 57.631391] [IGT] gem_tiled_pread_basic: executing <3>[ 123.820940] INFO: task kswapd0:80 blocked for more than 60 seconds. <3>[ 123.820963] Tainted: G U 4.15.0-rc3-CI-CI_DRM_3513+ #1 <3>[ 123.820983] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 123.821006] kswapd0 D 0 80 2 0x80000000 <4>[ 123.821011] Call Trace: <4>[ 123.821019] ? __schedule+0x3c3/0xaf0 <4>[ 123.821027] schedule+0x37/0x90 <4>[ 123.821031] io_schedule+0xd/0x30 <4>[ 123.821034] __lock_page+0x107/0x130 <4>[ 123.821039] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 123.821046] deferred_split_scan+0x25a/0x2b0 <4>[ 123.821053] shrink_slab.part.17+0x201/0x5d0 <4>[ 123.821065] shrink_node+0x2fd/0x310 <4>[ 123.821073] kswapd+0x31c/0x910 <4>[ 123.821085] kthread+0x173/0x1b0 <4>[ 123.821088] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 123.821090] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.821095] ret_from_fork+0x24/0x30 <4>[ 123.821105] <4>[ 123.821105] Showing all locks held in the system: <4>[ 123.821113] 2 locks held by khungtaskd/67: <4>[ 123.821116] #0: (rcu_read_lock){....}, at: [<00000000899df8e4>] watchdog+0x9b/0x5e0 <4>[ 123.821127] #1: (tasklist_lock){.+.+}, at: [<00000000bcdb3c63>] debug_show_all_locks+0x37/0x190 <4>[ 123.821139] 1 lock held by kswapd0/80: <4>[ 123.821141] #0: (shrinker_rwsem){++++}, at: [<000000008a60ca11>] shrink_slab.part.17+0x46/0x5d0 <4>[ 123.821157] 1 lock held by in:imklog/593: <4>[ 123.821159] #0: (&f->f_pos_lock){+.+.}, at: [<00000000109958e5>] __fdget_pos+0x40/0x50 <4>[ 123.821172] 2 locks held by systemd-hostnam/767: <4>[ 123.821174] #0: (&type->s_umount_key#29){++++}, at: [<000000005dafd8e5>] deactivate_super+0x3e/0x50 <4>[ 123.821185] #1: (shrinker_rwsem){++++}, at: [<00000000771ee75f>] unregister_shrinker+0x10/0x60 <4>[ 123.821198] 1 lock held by dmesg/1079: <4>[ 123.821200] #0: (&user->lock){+.+.}, at: [<00000000eb7fbce0>] devkmsg_read+0x35/0x2f0 <4>[ 123.821213] 1 lock held by gem_tiled_pread/1526: <4>[ 123.821214] #0: (&type->s_umount_key#29){++++}, at: [<00000000c0065d2f>] iterate_supers+0x8d/0xf0 but igt@gem_tiled_swapping@non-threaded is last in run.log and we appear to run out of mem: <7>[ 22.506021] [IGT] gem_tiled_swapping: executing <6>[ 22.531591] gem_tiled_swapp (1433): drop_caches: 4 <7>[ 24.044626] [IGT] gem_tiled_swapping: starting subtest non-threaded <5>[ 24.206026] random: crng init done <6>[ 38.088325] Purging GPU memory, 51712 pages freed, 935 pages still pinned. <6>[ 41.465720] Purging GPU memory, 52224 pages freed, 935 pages still pinned. <6>[ 44.272472] Purging GPU memory, 51968 pages freed, 935 pages still pinned. <4>[ 47.709105] gem_tiled_swapp: page allocation failure: order:0, mode:0x14204d2(GFP_HIGHUSER|__GFP_RETRY_MAYFAIL|__GFP_RECLAIMABLE), nodemask=(null) <4>[ 47.709131] CPU: 5 PID: 1433 Comm: gem_tiled_swapp Tainted: G U 4.15.0-rc3-CI-CI_DRM_3513+ #1 <4>[ 47.709133] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 47.709135] Call Trace: <4>[ 47.709141] dump_stack+0x5f/0x86 <4>[ 47.709146] warn_alloc+0xad/0x130 <4>[ 47.709153] ? __mutex_unlock_slowpath+0x38/0x270 <4>[ 47.709159] __alloc_pages_nodemask+0xeb5/0x11d0 <4>[ 47.709175] __read_swap_cache_async+0x146/0x250 <4>[ 47.709180] swapin_readahead+0x14b/0x230 <4>[ 47.709191] ? shmem_swapin+0x40/0x50 <4>[ 47.709194] shmem_swapin+0x40/0x50 <4>[ 47.709198] ? find_get_entry+0x160/0x210 <4>[ 47.709202] ? pagecache_get_page+0x2b/0x230 <4>[ 47.709207] ? lookup_swap_cache+0x46/0x100 <4>[ 47.709211] shmem_getpage_gfp.isra.9+0x925/0xc90 <4>[ 47.709222] shmem_read_mapping_page_gfp+0x2e/0x50 <4>[ 47.709251] i915_gem_object_get_pages_gtt+0x13b/0x660 [i915] <4>[ 47.709278] ? i915_gem_obj_prepare_shmem_write+0x190/0x220 [i915] <4>[ 47.709299] ____i915_gem_object_get_pages+0x17/0x70 [i915] <4>[ 47.709318] __i915_gem_object_get_pages+0x59/0x80 [i915] <4>[ 47.709339] i915_gem_set_domain_ioctl+0x377/0x3e0 [i915] <4>[ 47.709359] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 47.709363] drm_ioctl_kernel+0x60/0xa0 <4>[ 47.709367] drm_ioctl+0x290/0x330 <4>[ 47.709387] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 47.709392] ? vm_mmap_pgoff+0xa1/0xd0 <4>[ 47.709401] do_vfs_ioctl+0x8a/0x680 <4>[ 47.709404] ? entry_SYSCALL_64_fastpath+0x5/0x89 <4>[ 47.709408] ? trace_hardirqs_on_caller+0xde/0x1c0 <4>[ 47.709413] SyS_ioctl+0x36/0x70 <4>[ 47.709417] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 47.709420] RIP: 0033:0x7f4ed426a587 <4>[ 47.709422] RSP: 002b:00007fffba7f6cc8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 <4>[ 47.709425] RAX: ffffffffffffffda RBX: 0000000000000026 RCX: 00007f4ed426a587 <4>[ 47.709427] RDX: 00007fffba7f6d0c RSI: 00000000400c645f RDI: 0000000000000003 <4>[ 47.709429] RBP: 0000000000000098 R08: 0000000000000003 R09: 000000010fa00000 <4>[ 47.709431] R10: 0000000000000001 R11: 0000000000000246 R12: 000055a474724240 <4>[ 47.709433] R13: 00007f4ed5c5d000 R14: 0000000000000003 R15: 000000000000025f <4>[ 47.709461] Mem-Info: <4>[ 47.709465] active_anon:2810 inactive_anon:53101 isolated_anon:32 active_file:79 inactive_file:76 isolated_file:0 unevictable:3836673 dirty:5 writeback:0 unstable:0 slab_reclaimable:7694 slab_unreclaimable:16315 mapped:1000 shmem:53120 pagetables:8816 bounce:0 free:33343 free_pcp:30 free_cma:0 <4>[ 47.709469] Node 0 active_anon:11240kB inactive_anon:212404kB active_file:316kB inactive_file:304kB unevictable:15346692kB isolated(anon):128kB isolated(file):0kB mapped:4000kB dirty:20kB writeback:0kB shmem:212480kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 14948352kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no <4>[ 47.709472] DMA free:15884kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15884kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 47.709474] lowmem_reserve[]: 0 2894 15416 15416 <4>[ 47.709485] DMA32 free:62488kB min:12676kB low:15844kB high:19012kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:2970008kB writepending:0kB present:3077188kB managed:3032508kB mlocked:2970008kB kernel_stack:0kB pagetables:8kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 47.709487] lowmem_reserve[]: 0 0 12522 12522 <4>[ 47.709498] Normal free:55000kB min:54836kB low:68544kB high:82252kB active_anon:11240kB inactive_anon:212404kB active_file:316kB inactive_file:304kB unevictable:12376684kB writepending:20kB present:13105152kB managed:12823268kB mlocked:12376684kB kernel_stack:3760kB pagetables:35256kB bounce:0kB free_pcp:120kB local_pcp:0kB free_cma:0kB <4>[ 47.709500] lowmem_reserve[]: 0 0 0 0 <4>[ 47.709509] DMA: 3*4kB (U) 2*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15884kB <4>[ 47.709544] DMA32: 4*4kB (UM) 3*8kB (U) 3*16kB (U) 4*32kB (UM) 1*64kB (U) 0*128kB 9*256kB (UM) 9*512kB (UM) 6*1024kB (UM) 2*2048kB (UM) 11*4096kB (M) = 62488kB <4>[ 47.709582] Normal: 2436*4kB (UME) 1167*8kB (UME) 633*16kB (UM) 250*32kB (UM) 100*64kB (UME) 53*128kB (UME) 16*256kB (M) 1*512kB (M) 0*1024kB 0*2048kB 0*4096kB = 55000kB <6>[ 47.709617] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB <4>[ 47.709618] 54774 total pagecache pages <4>[ 47.709669] 1490 pages in swap cache <4>[ 47.709671] Swap cache stats: add 852548, delete 851079, find 285364/336301 <4>[ 47.709672] Free swap = 1349884kB <4>[ 47.709674] Total swap = 2097148kB <4>[ 47.709676] 4049582 pages RAM <4>[ 47.709677] 0 pages HighMem/MovableOnly <4>[ 47.709679] 81667 pages reserved <6>[ 47.740907] Purging GPU memory, 51968 pages freed, 935 pages still pinned. <6>[ 51.532571] Purging GPU memory, 51968 pages freed, 935 pages still pinned. <6>[ 54.663518] Purging GPU memory, 51968 pages freed, 935 pages still pinned. https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3520/shard-snb2/igt@kms_plane_lowres@pipe-b-tiling-none.html run.log: running: igt/gem_tiled_swapping/non-threaded [08/76] skip: 3, pass: 5 | FATAL: command execution failed java.io.EOFException ... CI_IGT_test runtime 152 seconds Rebooting shard-snb2 dmesg: <7>[ 32.977139] [IGT] gem_tiled_swapping: executing <6>[ 32.997404] gem_tiled_swapp (1553): drop_caches: 4 <7>[ 34.348389] [IGT] gem_tiled_swapping: starting subtest non-threaded ... <7>[ 123.271626] [IGT] kms_frontbuffer_tracking: starting subtest fbcpsr-1p-primscrn-cur-indfb-draw-mmap-gtt <7>[ 123.271973] [IGT] kms_frontbuffer_tracking: exiting, ret=77 <6>[ 123.314223] Console: switching to colour frame buffer device 128x48 <6>[ 123.421863] Console: switching to colour dummy device 80x25 <7>[ 123.421910] [IGT] kms_ccs: executing <7>[ 123.430763] [IGT] kms_ccs: exiting, ret=77 <6>[ 123.447962] Console: switching to colour frame buffer device 128x48 https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4064/shard-hsw1/igt@tools_test@sysfs_l3_parity.html run.log: running: igt/gem_tiled_swapping/non-threaded [12/76] skip: 7, pass: 5 | FATAL: command execution failed ... CI_IGT_test runtime 156 seconds Rebooting shard-hsw1 dmesg: <7>[ 14.674798] [IGT] gem_tiled_swapping: executing <5>[ 16.001694] random: crng init done <7>[ 16.031139] [IGT] gem_tiled_swapping: starting subtest non-threaded <6>[ 36.481077] Purging GPU memory, 49664 pages freed, 935 pages still pinned. <6>[ 41.760477] Purging GPU memory, 49920 pages freed, 935 pages still pinned. <6>[ 45.495909] Purging GPU memory, 50176 pages freed, 935 pages still pinned. <4>[ 49.314504] gem_tiled_swapp: page allocation failure: order:0, mode:0x14204d2(GFP_HIGHUSER|__GFP_RETRY_MAYFAIL|__GFP_RECLAIMABLE), nodemask=(null) <4>[ 49.314529] CPU: 5 PID: 1377 Comm: gem_tiled_swapp Tainted: G U 4.15.0-rc3-CI-CI_DRM_3521+ #1 <4>[ 49.314531] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 49.314533] Call Trace: <4>[ 49.314538] dump_stack+0x5f/0x86 <4>[ 49.314543] warn_alloc+0xad/0x130 <4>[ 49.314551] ? __mutex_unlock_slowpath+0x38/0x270 <4>[ 49.314556] __alloc_pages_nodemask+0xeb5/0x11d0 <4>[ 49.314572] __read_swap_cache_async+0x146/0x250 <4>[ 49.314578] swapin_readahead+0x14b/0x230 <4>[ 49.314588] ? shmem_swapin+0x40/0x50 <4>[ 49.314590] shmem_swapin+0x40/0x50 <4>[ 49.314594] ? find_get_entry+0x160/0x210 <4>[ 49.314599] ? pagecache_get_page+0x2b/0x230 <4>[ 49.314604] ? lookup_swap_cache+0x46/0x100 <4>[ 49.314607] shmem_getpage_gfp.isra.9+0x925/0xc90 <4>[ 49.314618] shmem_read_mapping_page_gfp+0x2e/0x50 <4>[ 49.314645] i915_gem_object_get_pages_gtt+0x13b/0x660 [i915] <4>[ 49.314671] ? i915_gem_obj_prepare_shmem_write+0x160/0x220 [i915] <4>[ 49.314692] ____i915_gem_object_get_pages+0x17/0x70 [i915] <4>[ 49.314711] __i915_gem_object_get_pages+0x59/0x80 [i915] <4>[ 49.314731] i915_gem_set_domain_ioctl+0x377/0x3e0 [i915] <4>[ 49.314751] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 49.314755] drm_ioctl_kernel+0x60/0xa0 <4>[ 49.314759] drm_ioctl+0x290/0x330 <4>[ 49.314779] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 49.314784] ? vm_mmap_pgoff+0xa1/0xd0 <4>[ 49.314792] do_vfs_ioctl+0x8a/0x680 <4>[ 49.314795] ? entry_SYSCALL_64_fastpath+0x5/0x89 <4>[ 49.314799] ? trace_hardirqs_on_caller+0xde/0x1c0 <4>[ 49.314804] SyS_ioctl+0x36/0x70 <4>[ 49.314808] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 49.314811] RIP: 0033:0x7ff9bfd2b587 <4>[ 49.314812] RSP: 002b:00007ffc2bf69768 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 <4>[ 49.314816] RAX: ffffffffffffffda RBX: 0000000000000208 RCX: 00007ff9bfd2b587 <4>[ 49.314818] RDX: 00007ffc2bf697ac RSI: 00000000400c645f RDI: 0000000000000003 <4>[ 49.314820] RBP: 0000000000000820 R08: 0000000000000003 R09: 0000000103400000 <4>[ 49.314821] R10: 0000000000000001 R11: 0000000000000246 R12: 0000561a5a6bb240 <4>[ 49.314823] R13: 00007ff9c171e000 R14: 0000000000000003 R15: 00000000000001c4 <4>[ 49.314849] Mem-Info: <4>[ 49.314853] active_anon:3609 inactive_anon:52097 isolated_anon:64 active_file:183 inactive_file:0 isolated_file:0 unevictable:3836673 dirty:6 writeback:0 unstable:0 slab_reclaimable:7469 slab_unreclaimable:16527 mapped:1051 shmem:51116 pagetables:8793 bounce:0 free:33246 free_pcp:0 free_cma:0 <4>[ 49.314856] Node 0 active_anon:14436kB inactive_anon:208388kB active_file:732kB inactive_file:0kB unevictable:15346692kB isolated(anon):256kB isolated(file):0kB mapped:4204kB dirty:24kB writeback:0kB shmem:204464kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 14983168kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no <4>[ 49.314860] DMA free:15884kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15884kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 49.314862] lowmem_reserve[]: 0 2894 15416 15416 <4>[ 49.314873] DMA32 free:62600kB min:12676kB low:15844kB high:19012kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:2969896kB writepending:0kB present:3077188kB managed:3032508kB mlocked:2969896kB kernel_stack:0kB pagetables:8kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 49.314874] lowmem_reserve[]: 0 0 12522 12522 <4>[ 49.314885] Normal free:54500kB min:54836kB low:68544kB high:82252kB active_anon:14436kB inactive_anon:208388kB active_file:472kB inactive_file:436kB unevictable:12376796kB writepending:24kB present:13105152kB managed:12823268kB mlocked:12376796kB kernel_stack:3760kB pagetables:35164kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 49.314887] lowmem_reserve[]: 0 0 0 0 <4>[ 49.314896] DMA: 3*4kB (U) 2*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15884kB <4>[ 49.314929] DMA32: 2*4kB (UM) 2*8kB (U) 3*16kB (UM) 2*32kB (U) 0*64kB 2*128kB (UM) 9*256kB (UM) 9*512kB (UM) 6*1024kB (UM) 2*2048kB (UM) 11*4096kB (M) = 62600kB <4>[ 49.314966] Normal: 2344*4kB (UME) 1174*8kB (UME) 639*16kB (UME) 310*32kB (UME) 151*64kB (UME) 53*128kB (UME) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 55360kB <6>[ 49.314997] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB <4>[ 49.314999] 53975 total pagecache pages <4>[ 49.315003] 2600 pages in swap cache <4>[ 49.315005] Swap cache stats: add 1100872, delete 1098357, find 392943/463271 <4>[ 49.315007] Free swap = 1360636kB <4>[ 49.315008] Total swap = 2097148kB <4>[ 49.315010] 4049582 pages RAM <4>[ 49.315012] 0 pages HighMem/MovableOnly <4>[ 49.315013] 81667 pages reserved <6>[ 49.540631] Purging GPU memory, 49920 pages freed, 935 pages still pinned. <7>[ 51.122908] [IGT] gem_tiled_swapping: exiting, ret=0 <7>[ 52.042053] [IGT] tools_test: executing https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4065/shard-hsw1/igt@kms_flip@2x-plain-flip.html run.log: running: igt/gem_tiled_swapping/non-threaded [05/76] skip: 4, pass: 1 / FATAL: command execution failed ... CI_IGT_test runtime 161 seconds Rebooting shard-hsw1 dmesg: <7>[ 13.358466] [IGT] gem_tiled_swapping: executing <6>[ 13.394024] gem_tiled_swapp (2371): drop_caches: 4 <7>[ 14.957300] [IGT] gem_tiled_swapping: starting subtest non-threaded <5>[ 15.622972] random: crng init done <6>[ 37.256936] Purging GPU memory, 50944 pages freed, 935 pages still pinned. <6>[ 42.864843] Purging GPU memory, 51200 pages freed, 1191 pages still pinned. <6>[ 46.506086] Purging GPU memory, 51456 pages freed, 935 pages still pinned. <7>[ 49.122289] [IGT] gem_tiled_swapping: exiting, ret=0 <7>[ 49.978209] [IGT] kms_flip: executing https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3523/shard-hsw6/igt@kms_flip@blt-wf_vblank-vs-modeset-interruptible.html run.log: running: igt/gem_tiled_swapping/non-threaded [17/76] skip: 8, pass: 9 / FATAL: command execution failed java.io.EOFException ... Completed CI_IGT_test CI_DRM_3523/shard-hsw6/24 : FAILURE CI_IGT_test runtime 276 seconds Rebooting shard-hsw6 pstore: <7>[ 246.768557] [drm:intel_reference_shared_dpll [i915]] using SPLL for pipe C <3>[ 246.864103] INFO: task kswapd0:80 blocked for more than 60 seconds. <3>[ 246.864126] Tainted: G U 4.15.0-rc3-CI-CI_DRM_3523+ #1 <3>[ 246.864136] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 246.864146] kswapd0 D 0 80 2 0x80000000 <4>[ 246.864163] Call Trace: <4>[ 246.864185] ? __schedule+0x3c3/0xaf0 <4>[ 246.864211] schedule+0x37/0x90 <4>[ 246.864222] io_schedule+0xd/0x30 <4>[ 246.864233] __lock_page+0x107/0x130 <4>[ 246.864250] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 246.864271] deferred_split_scan+0x25a/0x2b0 <4>[ 246.864284] shrink_slab.part.17+0x201/0x5d0 <4>[ 246.864305] shrink_node+0x2fd/0x310 <4>[ 246.864320] kswapd+0x31c/0x910 <4>[ 246.864341] kthread+0x173/0x1b0 <4>[ 246.864347] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 246.864352] ? _kthread_create_on_node+0x30/0x30 <4>[ 246.864360] ret_from_fork+0x24/0x30 <4>[ 246.864378] <4>[ 246.864378] Showing all locks held in the system: <4>[ 246.864388] 2 locks held by khungtaskd/67: <4>[ 246.864395] #0: (rcu_read_lock){....}, at: [<00000000d5a49218>] watchdog+0x9b/0x5e0 <4>[ 246.864416] #1: (tasklist_lock){.+.+}, at: [<000000005d61d7e3>] debug_show_all_locks+0x37/0x190 <4>[ 246.864437] 1 lock held by kswapd0/80: <4>[ 246.864440] #0: (shrinker_rwsem){++++}, at: [<000000005a3fbf39>] shrink_slab.part.17+0x46/0x5d0 <4>[ 246.864465] 1 lock held by systemd-journal/229: <4>[ 246.864468] #0: (&mm->mmap_sem){++++}, at: [<00000000896672dd>] __do_page_fault+0x106/0x560 <4>[ 246.864493] 1 lock held by in:imklog/587: <4>[ 246.864496] #0: (&f->f_pos_lock){+.+.}, at: [<00000000b4ab2786>] __fdget_pos+0x40/0x50 <4>[ 246.864524] 1 lock held by dmesg/1086: <4>[ 246.864527] #0: (&user->lock){+.+.}, at: [<0000000028cca19f>] devkmsg_read+0x35/0x2f0 <4>[ 246.864550] 3 locks held by kms_flip/1786: <4>[ 246.864553] #0: (&dev->mode_config.mutex){+.+.}, at: [<000000008153aa3a>] drm_mode_setcrtc+0xba/0x5d0 <4>[ 246.864572] #1: (crtc_ww_class_acquire){+.+.}, at: [<00000000d02cfa34>] drm_mode_setcrtc+0xcc/0x5d0 <4>[ 246.864590] #2: (crtc_ww_class_mutex){+.+.}, at: [<00000000f306771c>] drm_modeset_backoff+0x7e/0x1c0 <4>[ 246.864609] <4>[ 246.864612] ============================================= <4>[ 246.864612] <4>[ 246.864617] NMI backtrace for cpu 1 <4>[ 246.864623] CPU: 1 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc3-CI-CI_DRM_3523+ #1 <4>[ 246.864627] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 246.864630] Call Trace: <4>[ 246.864639] dump_stack+0x5f/0x86 <4>[ 246.864646] nmi_cpu_backtrace+0xb4/0xc0 <4>[ 246.864654] ? irq_force_complete_move+0xe0/0xe0 <4>[ 246.864659] nmi_trigger_cpumask_backtrace+0xb8/0xf0 <4>[ 246.864667] watchdog+0x43e/0x5e0 <4>[ 246.864677] kthread+0x173/0x1b0 <4>[ 246.864682] ? reset_hung_task_detector+0x10/0x10 <4>[ 246.864687] ? _kthread_create_on_node+0x30/0x30 <4>[ 246.864694] ret_from_fork+0x24/0x30 <6>[ 246.864713] Sending NMI from CPU 1 to CPUs 0,2-7: <4>[ 246.864730] NMI backtrace for cpu 5 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864748] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864757] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864766] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864773] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864781] NMI backtrace for cpu 0 skipped: idling at intel_idle+0x6f/0x120 <4>[ 246.864788] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120 <0>[ 246.865728] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 246.865736] CPU: 1 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc3-CI-CI_DRM_3523+ #1 <4>[ 246.865741] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 246.865746] Call Trace: <4>[ 246.865756] dump_stack+0x5f/0x86 <4>[ 246.865764] panic+0xcf/0x20d <4>[ 246.865781] watchdog+0x44a/0x5e0 <4>[ 246.865792] kthread+0x173/0x1b0 <4>[ 246.865800] ? reset_hung_task_detector+0x10/0x10 <4>[ 246.865805] ? _kthread_create_on_node+0x30/0x30 <4>[ 246.865814] ret_from_fork+0x24/0x30 <0>[ 246.866626] Dumping ftrace buffer: <0>[ 246.866708] (ftrace buffer empty) <0>[ 246.866715] Kernel Offset: disabled https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3531/shard-hsw7/igt@kms_flip@vblank-vs-hang.html run.log: running: igt/gem_tiled_swapping/non-threaded [49/76] skip: 24, pass: 25 / FATAL: command execution failed java.io.EOFException ... CI_IGT_test runtime 234 seconds Rebooting shard-hsw7 pstore: <7>[ 184.837602] [drm:init_workarounds_ring [i915]] rcs0: Number of context specific w/a: 0 <3>[ 185.396854] INFO: task kswapd0:80 blocked for more than 60 seconds. <3>[ 185.396865] Tainted: G U 4.15.0-rc3-CI-CI_DRM_3531+ #1 <6>[ 185.396870] kswapd0 D 0 80 2 0x80000000 <4>[ 185.396875] Call Trace: <4>[ 185.396883] ? __schedule+0x3c3/0xaf0 <4>[ 185.396890] schedule+0x37/0x90 <4>[ 185.396895] io_schedule+0xd/0x30 <4>[ 185.396899] __lock_page+0x107/0x130 <4>[ 185.396903] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 185.396910] deferred_split_scan+0x25a/0x2b0 <4>[ 185.396917] shrink_slab.part.17+0x201/0x5d0 <4>[ 185.396927] shrink_node+0x2fd/0x310 <4>[ 185.396934] kswapd+0x31c/0x910 <4>[ 185.396945] kthread+0x173/0x1b0 <4>[ 185.396948] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 185.396950] ? _kthread_create_on_node+0x30/0x30 <4>[ 185.396955] ret_from_fork+0x24/0x30 <4>[ 185.396963] <4>[ 185.396963] Showing all locks held in the system: <4>[ 185.396972] 2 locks held by khungtaskd/67: <4>[ 185.396976] #0: (rcu_read_lock){....}, at: [<000000002436718a>] watchdog+0x9b/0x5e0 <4>[ 185.396987] #1: (tasklist_lock){.+.+}, at: [<00000000e0223fab>] debug_show_all_locks+0x37/0x190 <4>[ 185.396999] 1 lock held by kswapd0/80: <4>[ 185.397001] #0: (shrinker_rwsem){++++}, at: [<000000007ca46b62>] shrink_slab.part.17+0x46/0x5d0 <4>[ 185.397018] 1 lock held by in:imklog/602: <4>[ 185.397020] #0: (&f->f_pos_lock){+.+.}, at: [<0000000036b693d1>] __fdget_pos+0x40/0x50 <4>[ 185.397036] 1 lock held by dmesg/1090: <4>[ 185.397038] #0: (&user->lock){+.+.}, at: [<00000000400b3ddf>] devkmsg_read+0x35/0x2f0 <4>[ 185.397061] <4>[ 185.397063] ============================================= <4>[ 185.397063] <4>[ 185.397065] NMI backtrace for cpu 0 <4>[ 185.397068] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc3-CI-CI_DRM_3531+ #1 <4>[ 185.397070] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 185.397071] Call Trace: <4>[ 185.397075] dump_stack+0x5f/0x86 <4>[ 185.397079] nmi_cpu_backtrace+0xb4/0xc0 <4>[ 185.397084] ? lapic_can_unplug_cpu+0x90/0x90 <4>[ 185.397087] nmi_trigger_cpumask_backtrace+0xb8/0xf0 <4>[ 185.397091] watchdog+0x43e/0x5e0 <4>[ 185.397095] kthread+0x173/0x1b0 <4>[ 185.397098] ? reset_hung_task_detector+0x10/0x10 <4>[ 185.397100] ? _kthread_create_on_node+0x30/0x30 <4>[ 185.397104] ret_from_fork+0x24/0x30 <6>[ 185.397113] Sending NMI from CPU 0 to CPUs 1-7: <4>[ 185.397121] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397135] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397137] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397141] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397145] NMI backtrace for cpu 5 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397148] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120 <4>[ 185.397151] NMI backtrace for cpu 1 skipped: idling at intel_idle+0x6f/0x120 <0>[ 185.398121] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 185.398126] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc3-CI-CI_DRM_3531+ #1 <4>[ 185.398129] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 185.398131] Call Trace: <4>[ 185.398136] dump_stack+0x5f/0x86 <4>[ 185.398141] panic+0xcf/0x20d <4>[ 185.398150] watchdog+0x44a/0x5e0 <4>[ 185.398156] kthread+0x173/0x1b0 <4>[ 185.398159] ? reset_hung_task_detector+0x10/0x10 <4>[ 185.398162] ? _kthread_create_on_node+0x30/0x30 <4>[ 185.398168] ret_from_fork+0x24/0x30 <0>[ 185.398576] Dumping ftrace buffer: <0>[ 185.398642] (ftrace buffer empty) <0>[ 185.398646] Kernel Offset: disabled https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3536/shard-hsw5/igt@kms_frontbuffer_tracking@psr-1p-primscrn-spr-indfb-draw-pwrite.html run.log: running: igt/gem_tiled_swapping/non-threaded [01/76] skip: 1 / FATAL: command execution failed ... CI_IGT_test runtime 148 seconds Rebooting shard-hsw5 no pstore, however dmesg has page allocation failure: <7>[ 17.216349] [IGT] gem_tiled_swapping: starting subtest non-threaded <5>[ 17.471796] random: crng init done <4>[ 35.220136] gem_tiled_swapp: page allocation failure: order:0, mode:0x14204d2(GFP_HIGHUSER|__GFP_RETRY_MAYFAIL|__GFP_RECLAIMABLE), nodemask=(null) <4>[ 35.220161] CPU: 5 PID: 1337 Comm: gem_tiled_swapp Not tainted 4.15.0-rc3-CI-CI_DRM_3536+ #1 <4>[ 35.220162] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 35.220164] Call Trace: <4>[ 35.220169] dump_stack+0x5f/0x86 <4>[ 35.220174] warn_alloc+0xad/0x130 <4>[ 35.220181] ? __mutex_unlock_slowpath+0x38/0x270 <4>[ 35.220186] __alloc_pages_nodemask+0xeb5/0x11d0 <4>[ 35.220202] __read_swap_cache_async+0x146/0x250 <4>[ 35.220208] swapin_readahead+0x14b/0x230 <4>[ 35.220218] ? shmem_swapin+0x40/0x50 <4>[ 35.220220] shmem_swapin+0x40/0x50 <4>[ 35.220225] ? find_get_entry+0x160/0x210 <4>[ 35.220229] ? pagecache_get_page+0x2b/0x230 <4>[ 35.220234] ? lookup_swap_cache+0x46/0x100 <4>[ 35.220237] shmem_getpage_gfp.isra.9+0x925/0xc90 <4>[ 35.220248] shmem_read_mapping_page_gfp+0x2e/0x50 <4>[ 35.220277] i915_gem_object_get_pages_gtt+0x13b/0x660 [i915] <4>[ 35.220304] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 35.220323] ____i915_gem_object_get_pages+0x17/0x70 [i915] <4>[ 35.220343] __i915_gem_object_get_pages+0x59/0x80 [i915] <4>[ 35.220363] i915_gem_set_domain_ioctl+0x377/0x3e0 [i915] <4>[ 35.220383] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 35.220387] drm_ioctl_kernel+0x60/0xa0 <4>[ 35.220391] drm_ioctl+0x290/0x330 <4>[ 35.220411] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 35.220417] ? vm_mmap_pgoff+0xa1/0xd0 <4>[ 35.220425] do_vfs_ioctl+0x8a/0x680 <4>[ 35.220428] ? entry_SYSCALL_64_fastpath+0x5/0x89 <4>[ 35.220432] ? trace_hardirqs_on_caller+0xde/0x1c0 <4>[ 35.220436] SyS_ioctl+0x36/0x70 <4>[ 35.220441] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 35.220443] RIP: 0033:0x7f0921008587 <4>[ 35.220445] RSP: 002b:00007ffee6321228 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 <4>[ 35.220449] RAX: ffffffffffffffda RBX: 00000000000001ed RCX: 00007f0921008587 <4>[ 35.220450] RDX: 00007ffee632126c RSI: 00000000400c645f RDI: 0000000000000003 <4>[ 35.220452] RBP: 00000000000007b4 R08: 0000000000000003 R09: 0000000107200000 <4>[ 35.220454] R10: 0000000000000001 R11: 0000000000000246 R12: 000055d074a98240 <4>[ 35.220455] R13: 00007f09229fb000 R14: 0000000000000003 R15: 000000000000010a <4>[ 35.220478] Mem-Info: <4>[ 35.220482] active_anon:15445 inactive_anon:40672 isolated_anon:0 active_file:158 inactive_file:24 isolated_file:0 unevictable:3836673 dirty:2 writeback:0 unstable:0 slab_reclaimable:7406 slab_unreclaimable:16278 mapped:989 shmem:39096 pagetables:8876 bounce:0 free:33353 free_pcp:0 free_cma:0 <4>[ 35.220486] Node 0 active_anon:61780kB inactive_anon:162688kB active_file:632kB inactive_file:96kB unevictable:15346692kB isolated(anon):0kB isolated(file):0kB mapped:3956kB dirty:8kB writeback:0kB shmem:156384kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 15034368kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no <4>[ 35.220489] DMA free:15884kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15884kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 35.220491] lowmem_reserve[]: 0 2894 15416 15416 <4>[ 35.220502] DMA32 free:62724kB min:12676kB low:15844kB high:19012kB active_anon:12kB inactive_anon:1964kB active_file:0kB inactive_file:0kB unevictable:2967624kB writepending:0kB present:3077188kB managed:3032468kB mlocked:2967624kB kernel_stack:0kB pagetables:4kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 35.220504] lowmem_reserve[]: 0 0 12522 12522 <4>[ 35.220515] Normal free:54804kB min:54836kB low:68544kB high:82252kB active_anon:61768kB inactive_anon:160724kB active_file:372kB inactive_file:380kB unevictable:12379068kB writepending:8kB present:13105152kB managed:12823268kB mlocked:12379068kB kernel_stack:3840kB pagetables:35500kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 35.220516] lowmem_reserve[]: 0 0 0 0 <4>[ 35.220525] DMA: 3*4kB (U) 2*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15884kB <4>[ 35.220559] DMA32: 5*4kB (ME) 4*8kB (M) 5*16kB (UME) 4*32kB (UM) 6*64kB (UME) 3*128kB (ME) 9*256kB (UME) 10*512kB (UME) 7*1024kB (UME) 3*2048kB (UM) 10*4096kB (M) = 62724kB <4>[ 35.220598] Normal: 2827*4kB (UM) 1542*8kB (UME) 558*16kB (UME) 265*32kB (UME) 132*64kB (UME) 37*128kB (UME) 3*256kB (ME) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 55004kB <6>[ 35.220631] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB <4>[ 35.220633] 42906 total pagecache pages <4>[ 35.220637] 3622 pages in swap cache <4>[ 35.220639] Swap cache stats: add 776597, delete 772999, find 248832/296870 <4>[ 35.220640] Free swap = 1331196kB <4>[ 35.220642] Total swap = 2097148kB <4>[ 35.220644] 4049582 pages RAM <4>[ 35.220645] 0 pages HighMem/MovableOnly <4>[ 35.220647] 81677 pages reserved <6>[ 35.344763] Purging GPU memory, 37888 pages freed, 918 pages still pinned. <6>[ 38.241462] Purging GPU memory, 37888 pages freed, 918 pages still pinned. <6>[ 40.758512] Purging GPU memory, 37632 pages freed, 918 pages still pinned. <6>[ 43.458096] Purging GPU memory, 38400 pages freed, 918 pages still pinned. <6>[ 45.888864] Purging GPU memory, 38144 pages freed, 918 pages still pinned. <6>[ 49.200430] Purging GPU memory, 38144 pages freed, 918 pages still pinned. <7>[ 49.787596] [IGT] gem_tiled_swapping: exiting, ret=0 <7>[ 50.603454] [IGT] kms_frontbuffer_tracking: executing https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3540/shard-snb5/igt@kms_flip@flip-vs-panning-interruptible.html run.log: running: igt/gem_tiled_swapping/non-threaded [51/76] skip: 26, pass: 25 \ FATAL: command execution failed dmesg: <7>[ 108.364472] [IGT] gem_tiled_swapping: executing <7>[ 109.750063] [IGT] gem_tiled_swapping: starting subtest non-threaded ... <6>[ 166.322120] Console: switching to colour dummy device 80x25 <7>[ 166.322168] [IGT] kms_flip: executing Followed by stray https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3568/shard-hsw6/igt@kms_draw_crc@draw-method-xrgb2101010-mmap-gtt-untiled.html <5>[ 31.693010] random: crng init done <14>[ 32.107395] [IGT] gem_tiled_swapping: starting subtest non-threaded <6>[ 58.761579] Purging GPU memory, 53504 pages freed, 918 pages still pinned. <14>[ 60.652382] [IGT] gem_tiled_swapping: exiting, ret=0 <14>[ 61.450548] [IGT] kms_draw_crc: executing <3>[ 123.823341] INFO: task kswapd0:80 blocked for more than 60 seconds. <3>[ 123.823355] Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <3>[ 123.823364] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 123.823376] kswapd0 D 0 80 2 0x80000000 <4>[ 123.823379] Call Trace: <4>[ 123.823385] ? __schedule+0x3c3/0xaf0 <4>[ 123.823389] schedule+0x37/0x90 <4>[ 123.823392] io_schedule+0xd/0x30 <4>[ 123.823395] __lock_page+0x107/0x130 <4>[ 123.823397] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 123.823401] deferred_split_scan+0x25a/0x2b0 <4>[ 123.823406] shrink_slab.part.17+0x201/0x5d0 <4>[ 123.823412] shrink_node+0x2fd/0x310 <4>[ 123.823417] kswapd+0x31c/0x910 <4>[ 123.823423] kthread+0xfb/0x130 <4>[ 123.823425] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 123.823426] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.823429] ret_from_fork+0x24/0x30 <4>[ 123.823434] <4>[ 123.823434] Showing all locks held in the system: <4>[ 123.823440] 2 locks held by khungtaskd/67: <4>[ 123.823442] #0: (rcu_read_lock){....}, at: [<0000000073142e66>] watchdog+0x9b/0x5e0 <4>[ 123.823449] #1: (tasklist_lock){.+.+}, at: [<000000008bb68302>] debug_show_all_locks+0x37/0x190 <4>[ 123.823456] 1 lock held by kswapd0/80: <4>[ 123.823457] #0: (shrinker_rwsem){++++}, at: [<00000000222c0c5d>] shrink_slab.part.17+0x46/0x5d0 <4>[ 123.823472] 1 lock held by in:imklog/586: <4>[ 123.823473] #0: (&f->f_pos_lock){+.+.}, at: [<00000000a31cfa2e>] __fdget_pos+0x3a/0x50 <4>[ 123.823481] 2 locks held by systemd-hostnam/764: <4>[ 123.823481] #0: (&type->s_umount_key#29){++++}, at: [<000000001e90c47d>] deactivate_super+0x3e/0x50 <4>[ 123.823488] #1: (shrinker_rwsem){++++}, at: [<00000000bf09f442>] unregister_shrinker+0x10/0x60 <4>[ 123.823496] 1 lock held by dmesg/1160: <4>[ 123.823497] #0: (&user->lock){+.+.}, at: [<00000000a9303139>] devkmsg_read+0x35/0x2f0 <4>[ 123.823513] 1 lock held by kms_draw_crc/1615: <4>[ 123.823514] #0: (&type->s_umount_key#29){++++}, at: [<000000003cf12e6f>] iterate_supers+0x8d/0xf0 <4>[ 123.823520] <4>[ 123.823521] ============================================= <4>[ 123.823521] <4>[ 123.823522] NMI backtrace for cpu 0 <4>[ 123.823524] CPU: 0 PID: 67 Comm: khungtaskd Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.823525] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 123.823526] Call Trace: <4>[ 123.823528] dump_stack+0x5f/0x86 <4>[ 123.823530] nmi_cpu_backtrace+0xb4/0xc0 <4>[ 123.823534] ? lapic_can_unplug_cpu+0x90/0x90 <4>[ 123.823536] nmi_trigger_cpumask_backtrace+0xb8/0xf0 <4>[ 123.823539] watchdog+0x43e/0x5e0 <4>[ 123.823541] kthread+0xfb/0x130 <4>[ 123.823543] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.823544] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.823546] ret_from_fork+0x24/0x30 <6>[ 123.823552] Sending NMI from CPU 0 to CPUs 1-7: <4>[ 123.823554] NMI backtrace for cpu 5 <4>[ 123.823556] CPU: 5 PID: 1064 Comm: java Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.823556] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 123.823569] RIP: 0010:lock_is_held_type+0x59/0x80 <4>[ 123.823570] RSP: 0018:ffffc90000b93dd8 EFLAGS: 00000092 <4>[ 123.823570] RAX: 0000000000000000 RBX: ffff880405da2880 RCX: 0000000000000001 <4>[ 123.823571] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff81e4b7c0 <4>[ 123.823571] RBP: ffff880405da27c0 R08: ffff880405da3098 R09: 00000000e0c4a53a <4>[ 123.823572] R10: ffffc90000b93d80 R11: ffffffff810b553f R12: 0000000000000092 <4>[ 123.823572] R13: ffff880409554248 R14: ffff880405da27c0 R15: ffff88041fb5ab40 <4>[ 123.823573] FS: 00007f9b58ace700(0000) GS:ffff88041fb40000(0000) knlGS:0000000000000000 <4>[ 123.823574] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 123.823574] CR2: 00007f9b730470a0 CR3: 0000000404958004 CR4: 00000000001606e0 <4>[ 123.823575] Call Trace: <4>[ 123.823577] update_curr+0x363/0x460 <4>[ 123.823578] pick_next_task_fair+0xa9/0x8a0 <4>[ 123.823581] __schedule+0x123/0xaf0 <4>[ 123.823582] schedule+0x37/0x90 <4>[ 123.823584] sys_sched_yield+0x8c/0xa0 <4>[ 123.823585] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 123.823586] RIP: 0033:0x7f9b730470a7 <4>[ 123.823586] RSP: 002b:00007f9b58acdc78 EFLAGS: 00000297 ORIG_RAX: 0000000000000018 <4>[ 123.823587] RAX: ffffffffffffffda RBX: 00007f9ae00aa000 RCX: 00007f9b730470a7 <4>[ 123.823587] RDX: 00007f9b728c8170 RSI: 00007f9b5d005300 RDI: 000000000317b28f <4>[ 123.823588] RBP: 00007f9b58acdd00 R08: 0000000000000000 R09: 00007f9b72907800 <4>[ 123.823588] R10: 0000000000000001 R11: 0000000000000297 R12: 00007f9ae00a8d40 <4>[ 123.823589] R13: 000000000317b132 R14: 0000000000000003 R15: 000000000317b131 <4>[ 123.823590] Code: 8b 2c 25 80 c5 00 00 48 89 df c7 85 ac 08 00 00 01 00 00 00 e8 99 b0 ff ff c7 85 ac 08 00 00 00 00 00 00 41 54 9d 48 83 c4 08 5b <5d> 41 5c c3 4c 89 e7 89 74 24 04 e8 57 f5 ff ff 8b 74 24 04 eb <4>[ 123.823606] NMI backtrace for cpu 1 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.823608] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.823610] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.823612] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.823614] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.823616] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120 <0>[ 123.824556] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 123.824566] CPU: 0 PID: 67 Comm: khungtaskd Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.824577] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 123.824588] Call Trace: <4>[ 123.824593] dump_stack+0x5f/0x86 <4>[ 123.824600] panic+0xcf/0x20d <4>[ 123.824608] watchdog+0x44a/0x5e0 <4>[ 123.824615] kthread+0xfb/0x130 <4>[ 123.824621] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.824629] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.824637] ret_from_fork+0x24/0x30 <0>[ 123.824885] Dumping ftrace buffer: <0>[ 123.824946] (ftrace buffer empty) https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3568/shard-kbl1/igt@kms_draw_crc@draw-method-xrgb2101010-mmap-gtt-untiled.html <14>[ 24.151933] [IGT] kms_cursor_crc: starting subtest cursor-512x170-sliding <14>[ 24.151997] [IGT] kms_cursor_crc: exiting, ret=77 <14>[ 24.213039] [IGT] gem_tiled_swapping: executing <6>[ 24.740852] e1000e: eno1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None <14>[ 25.065109] [IGT] gem_tiled_swapping: starting subtest non-threaded <4>[ 53.664359] gem_tiled_swapp: page allocation failure: order:0, mode:0x14204d2(GFP_HIGHUSER|__GFP_RETRY_MAYFAIL|__GFP_RECLAIMABLE), nodemask=(null) <4>[ 53.664384] CPU: 1 PID: 1495 Comm: gem_tiled_swapp Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 53.664387] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 53.664388] Call Trace: <4>[ 53.664394] dump_stack+0x5f/0x86 <4>[ 53.664399] warn_alloc+0xad/0x130 <4>[ 53.664406] ? __mutex_unlock_slowpath+0x38/0x270 <4>[ 53.664412] __alloc_pages_nodemask+0xeb5/0x11d0 <4>[ 53.664428] __read_swap_cache_async+0x141/0x250 <4>[ 53.664434] swapin_readahead+0x14b/0x230 <4>[ 53.664445] ? shmem_swapin+0x40/0x50 <4>[ 53.664447] shmem_swapin+0x40/0x50 <4>[ 53.664452] ? find_get_entry+0x160/0x210 <4>[ 53.664456] ? pagecache_get_page+0x2b/0x230 <4>[ 53.664461] ? lookup_swap_cache+0x3b/0xf0 <4>[ 53.664465] shmem_getpage_gfp.isra.9+0x91f/0xc80 <4>[ 53.664477] shmem_read_mapping_page_gfp+0x2e/0x50 <4>[ 53.664507] i915_gem_object_get_pages_gtt+0x13b/0x660 [i915] <4>[ 53.664538] ? i915_gem_obj_prepare_shmem_write+0x1b0/0x220 [i915] <4>[ 53.664561] ____i915_gem_object_get_pages+0x17/0x70 [i915] <4>[ 53.664584] __i915_gem_object_get_pages+0x59/0x80 [i915] <4>[ 53.664607] i915_gem_set_domain_ioctl+0x377/0x3e0 [i915] <4>[ 53.664632] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 53.664636] drm_ioctl_kernel+0x60/0xa0 <4>[ 53.664641] drm_ioctl+0x290/0x330 <4>[ 53.664666] ? i915_gem_obj_prepare_shmem_write+0x220/0x220 [i915] <4>[ 53.664671] ? __handle_mm_fault+0x83a/0xdc0 <4>[ 53.664681] do_vfs_ioctl+0x8a/0x670 <4>[ 53.664684] ? entry_SYSCALL_64_fastpath+0x5/0x89 <4>[ 53.664688] ? trace_hardirqs_on_caller+0xde/0x1c0 <4>[ 53.664693] SyS_ioctl+0x36/0x70 <4>[ 53.664697] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 53.664699] RIP: 0033:0x7ff7fce86587 <4>[ 53.664701] RSP: 002b:00007fff38d25758 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 <4>[ 53.664706] RAX: ffffffffffffffda RBX: 00007ff7fe879000 RCX: 00007ff7fce86587 <4>[ 53.664707] RDX: 00007fff38d2579c RSI: 00000000400c645f RDI: 0000000000000003 <4>[ 53.664709] RBP: 0000000000100000 R08: 0000000000000003 R09: 0000000104b00000 <4>[ 53.664711] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000000001 <4>[ 53.664713] R13: 00007ff7fe879000 R14: 0000000000000003 R15: 000000000000004c <4>[ 53.664767] Mem-Info: <4>[ 53.664772] active_anon:19795 inactive_anon:51910 isolated_anon:32 <4>[ 53.664772] active_file:59 inactive_file:0 isolated_file:0 <4>[ 53.664772] unevictable:1874945 dirty:26 writeback:0 unstable:0 <4>[ 53.664772] slab_reclaimable:6821 slab_unreclaimable:14453 <4>[ 53.664772] mapped:774 shmem:52156 pagetables:4991 bounce:0 <4>[ 53.664772] free:26672 free_pcp:0 free_cma:0 <4>[ 53.664776] Node 0 active_anon:79180kB inactive_anon:207640kB active_file:236kB inactive_file:0kB unevictable:7499780kB isolated(anon):128kB isolated(file):0kB mapped:3096kB dirty:104kB writeback:0kB shmem:208624kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 7153664kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no <4>[ 53.664779] DMA free:15892kB min:132kB low:164kB high:196kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15892kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 53.664781] lowmem_reserve[]: 0 1831 7817 7817 <4>[ 53.664793] DMA32 free:39416kB min:15804kB low:19752kB high:23700kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:1839348kB writepending:0kB present:1986972kB managed:1878772kB mlocked:1839348kB kernel_stack:0kB pagetables:4kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 53.664794] lowmem_reserve[]: 0 0 5985 5985 <4>[ 53.664806] Normal free:51380kB min:51644kB low:64552kB high:77460kB active_anon:79180kB inactive_anon:207640kB active_file:212kB inactive_file:144kB unevictable:5660432kB writepending:104kB present:6275072kB managed:6129624kB mlocked:5660432kB kernel_stack:3968kB pagetables:19960kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB <4>[ 53.664807] lowmem_reserve[]: 0 0 0 0 <4>[ 53.664816] DMA: 3*4kB (U) 3*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15892kB <4>[ 53.664851] DMA32: 0*4kB 1*8kB (U) 1*16kB (U) 1*32kB (U) 1*64kB (U) 7*128kB (UM) 10*256kB (UM) 6*512kB (UM) 8*1024kB (UM) 2*2048kB (UM) 5*4096kB (M) = 39416kB <4>[ 53.664890] Normal: 2865*4kB (UME) 1399*8kB (UME) 657*16kB (UM) 332*32kB (ME) 111*64kB (ME) 4*128kB (ME) 1*256kB (M) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 51660kB <6>[ 53.664925] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB <4>[ 53.664927] 53752 total pagecache pages <4>[ 53.664931] 1424 pages in swap cache <4>[ 53.664933] Swap cache stats: add 1063614, delete 1062202, find 386034/455333 <4>[ 53.664935] Free swap = 1457660kB <4>[ 53.664937] Total swap = 2097148kB <4>[ 53.664939] 2069508 pages RAM <4>[ 53.664940] 0 pages HighMem/MovableOnly <4>[ 53.664942] 63436 pages reserved <6>[ 53.708393] Purging GPU memory, 51200 pages freed, 2336 pages still pinned. <3>[ 53.708407] 1 and 0 pages still available in the bound and unbound GPU page lists. <14>[ 59.595834] [IGT] gem_tiled_swapping: exiting, ret=0 <14>[ 60.171881] [IGT] kms_draw_crc: executing <6>[ 87.410277] usb 1-3.1: new low-speed USB device number 5 using xhci_hcd <6>[ 87.505870] usb 1-3.1: New USB device found, idVendor=275d, idProduct=0ba6 <6>[ 87.505885] usb 1-3.1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 <6>[ 87.505895] usb 1-3.1: Product: USB OPTICAL MOUSE <6>[ 87.514169] input: USB OPTICAL MOUSE as /devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3.1/1-3.1:1.0/0003:275D:0BA6.0003/input/input12 <6>[ 87.515070] hid-generic 0003:275D:0BA6.0003: input,hidraw2: USB HID v1.11 Mouse [USB OPTICAL MOUSE ] on usb-0000:00:14.0-3.1/input0 <3>[ 123.925608] INFO: task kswapd0:52 blocked for more than 60 seconds. <3>[ 123.925704] Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <3>[ 123.925764] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 123.925845] kswapd0 D 0 52 2 0x80000000 <4>[ 123.925863] Call Trace: <4>[ 123.925895] ? __schedule+0x3c3/0xaf0 <4>[ 123.925923] schedule+0x37/0x90 <4>[ 123.925937] io_schedule+0xd/0x30 <4>[ 123.925949] __lock_page+0x107/0x130 <4>[ 123.925967] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 123.925989] deferred_split_scan+0x25a/0x2b0 <4>[ 123.926013] shrink_slab.part.17+0x201/0x5d0 <4>[ 123.926055] shrink_node+0x2fd/0x310 <4>[ 123.926085] kswapd+0x31c/0x910 <4>[ 123.926126] kthread+0xfb/0x130 <4>[ 123.926137] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 123.926146] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.926163] ret_from_fork+0x24/0x30 <4>[ 123.926197] <4>[ 123.926197] Showing all locks held in the system: <4>[ 123.926338] 2 locks held by khungtaskd/39: <4>[ 123.926363] #0: (rcu_read_lock){....}, at: [<00000000ead4b3f7>] watchdog+0x9b/0x5e0 <4>[ 123.926451] #1: (tasklist_lock){.+.+}, at: [<0000000080919296>] debug_show_all_locks+0x37/0x190 <4>[ 123.926537] 1 lock held by kswapd0/52: <4>[ 123.926551] #0: (shrinker_rwsem){++++}, at: [<000000006cab8d6b>] shrink_slab.part.17+0x46/0x5d0 <4>[ 123.926661] 2 locks held by systemd-hostnam/680: <4>[ 123.926673] #0: (&type->s_umount_key#29){++++}, at: [<000000001efd5b9a>] deactivate_super+0x3e/0x50 <4>[ 123.926742] #1: (shrinker_rwsem){++++}, at: [<00000000d595b380>] unregister_shrinker+0x10/0x60 <4>[ 123.926856] 1 lock held by kms_draw_crc/1699: <4>[ 123.926869] #0: (&type->s_umount_key#29){++++}, at: [<0000000068f69647>] iterate_supers+0x8d/0xf0 <4>[ 123.926940] <4>[ 123.926951] ============================================= <4>[ 123.926951] <4>[ 123.926965] NMI backtrace for cpu 0 <4>[ 123.926983] CPU: 0 PID: 39 Comm: khungtaskd Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.926995] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 123.927004] Call Trace: <4>[ 123.927024] dump_stack+0x5f/0x86 <4>[ 123.927045] nmi_cpu_backtrace+0xb4/0xc0 <4>[ 123.927069] ? lapic_can_unplug_cpu+0x90/0x90 <4>[ 123.927086] nmi_trigger_cpumask_backtrace+0xb8/0xf0 <4>[ 123.927111] watchdog+0x43e/0x5e0 <4>[ 123.927145] kthread+0xfb/0x130 <4>[ 123.927161] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.927174] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.927199] ret_from_fork+0x24/0x30 <6>[ 123.927341] Sending NMI from CPU 0 to CPUs 1-3: <4>[ 123.927364] NMI backtrace for cpu 2 <4>[ 123.927370] CPU: 2 PID: 953 Comm: dmesg Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.927373] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 123.927383] RIP: 0010:unwind_next_frame+0x4ed/0x700 <4>[ 123.927387] RSP: 0018:ffffc9000095b9a8 EFLAGS: 00000002 <4>[ 123.927391] RAX: ffffffff812928ff RBX: ffffc9000095b9e0 RCX: ffffffff81175d7b <4>[ 123.927394] RDX: ffffc9000095c000 RSI: ffffc9000095be00 RDI: ffffc9000095b9e0 <4>[ 123.927397] RBP: 0000000000000001 R08: ffffffff81175ccc R09: ffffffff81f8dd94 <4>[ 123.927399] R10: ffffffff81f8dd90 R11: 0000000000000000 R12: ffffffff81175d7c <4>[ 123.927402] R13: ffffc9000095bdc0 R14: ffffffff820e6690 R15: ffffc9000095be08 <4>[ 123.927406] FS: 00007fb6bacfc040(0000) GS:ffff88027ed00000(0000) knlGS:0000000000000000 <4>[ 123.927409] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 123.927412] CR2: 00007f6a3ea995d3 CR3: 000000025f429005 CR4: 00000000003606e0 <4>[ 123.927414] Call Trace: <4>[ 123.927424] __save_stack_trace+0x6e/0xd0 <4>[ 123.927436] ? ext4_file_write_iter+0x10f/0x3a0 <4>[ 123.927444] ? jbd2_journal_stop+0x1c4/0x500 <4>[ 123.927453] set_track+0x5c/0x120 <4>[ 123.927460] free_debug_processing+0x281/0x370 <4>[ 123.927465] ? jbd2_journal_stop+0x1c4/0x500 <4>[ 123.927472] __slab_free+0x39c/0x580 <4>[ 123.927482] ? mark_held_locks+0x64/0x90 <4>[ 123.927487] ? _raw_spin_unlock_irqrestore+0x4c/0x60 <4>[ 123.927490] ? _raw_spin_unlock_irqrestore+0x4c/0x60 <4>[ 123.927498] ? trace_hardirqs_on_caller+0xde/0x1c0 <4>[ 123.927502] ? _raw_spin_unlock_irqrestore+0x39/0x60 <4>[ 123.927509] ? debug_check_no_obj_freed+0x11f/0x230 <4>[ 123.927517] ? kmem_cache_free+0x28a/0x320 <4>[ 123.927523] ? jbd2_journal_stop+0x1c4/0x500 <4>[ 123.927526] kmem_cache_free+0x28a/0x320 <4>[ 123.927533] jbd2_journal_stop+0x1c4/0x500 <4>[ 123.927542] ? rcu_read_lock_sched_held+0x6f/0x80 <4>[ 123.927546] ? __mark_inode_dirty+0x3a1/0x690 <4>[ 123.927555] __ext4_journal_stop+0x31/0x90 <4>[ 123.927562] ext4_da_write_end+0x160/0x370 <4>[ 123.927571] generic_perform_write+0xef/0x1a0 <4>[ 123.927581] __generic_file_write_iter+0x13c/0x1b0 <4>[ 123.927590] ext4_file_write_iter+0x10f/0x3a0 <4>[ 123.927598] ? lock_acquire+0xaf/0x200 <4>[ 123.927605] __vfs_write+0xc5/0x130 <4>[ 123.927613] vfs_write+0xbd/0x1b0 <4>[ 123.927618] SyS_write+0x40/0xa0 <4>[ 123.927626] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 123.927630] RIP: 0033:0x7fb6ba3f68f0 <4>[ 123.927633] RSP: 002b:00007fff03230a48 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 <4>[ 123.927638] RAX: ffffffffffffffda RBX: 00005573b7cae0db RCX: 00007fb6ba3f68f0 <4>[ 123.927640] RDX: 000000000000002c RSI: 00005573b8220f70 RDI: 0000000000000001 <4>[ 123.927642] RBP: 00007fff03230cd0 R08: 00007fb6ba6c1760 R09: 00007fb6bacfc040 <4>[ 123.927645] R10: 0000000000000004 R11: 0000000000000246 R12: 00005573b7aab2bb <4>[ 123.927647] R13: 00005573b7cae0a0 R14: 00005573b7cae0b2 R15: 00007fff03230cc8 <4>[ 123.927655] Code: 00 00 00 48 89 df e8 c3 fa ff ff 84 c0 0f 84 6b fb ff ff 49 8b 47 f8 4c 89 7b 38 48 c7 43 50 00 00 00 00 c6 43 35 00 48 89 43 48 <41> 0f b6 46 04 c0 e8 04 3c 01 0f 84 a7 00 00 00 0f 83 8c fd ff <4>[ 123.927735] NMI backtrace for cpu 1 <4>[ 123.927742] CPU: 1 PID: 424 Comm: rs:main Q:Reg Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.927745] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 123.927759] RIP: 0010:rcu_segcblist_pend_cbs+0x5/0x20 <4>[ 123.927767] RSP: 0018:ffff88027ec83ec0 EFLAGS: 00000082 <4>[ 123.927772] RAX: 0000000000000001 RBX: ffff88027ec9b800 RCX: 1a707d6f00000000 <4>[ 123.927774] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff88027ec9b838 <4>[ 123.927777] RBP: ffff88027ec9b838 R08: 0000000000000000 R09: 0000000000000000 <4>[ 123.927779] R10: ffff88027ec83e88 R11: ffff88026e42b0f0 R12: ffffffff81e44500 <4>[ 123.927781] R13: ffffffff81e44500 R14: 0000000000000009 R15: 0000000000000000 <4>[ 123.927785] FS: 00007f2875357700(0000) GS:ffff88027ec80000(0000) knlGS:0000000000000000 <4>[ 123.927788] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 123.927791] CR2: 00007fc283e983a0 CR3: 0000000269645005 CR4: 00000000003606e0 <4>[ 123.927793] Call Trace: <4>[ 123.927798] <IRQ> <4>[ 123.927806] rcu_advance_cbs+0x25/0x70 <4>[ 123.927815] rcu_start_gp+0x29/0x50 <4>[ 123.927823] rcu_process_callbacks+0x44f/0x6f0 <4>[ 123.927834] __do_softirq+0xc1/0x4aa <4>[ 123.927845] irq_exit+0xa4/0xb0 <4>[ 123.927852] smp_apic_timer_interrupt+0x90/0x2d0 <4>[ 123.927858] apic_timer_interrupt+0x93/0xa0 <4>[ 123.927861] </IRQ> <4>[ 123.927869] RIP: 0010:lock_acquire+0xc4/0x200 <4>[ 123.927872] RSP: 0018:ffffc9000086fa78 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff11 <4>[ 123.927877] RAX: ffff88026e42a840 RBX: 0000000000000282 RCX: 524c906500000000 <4>[ 123.927879] RDX: 0000000000000001 RSI: 0000000083c6b9ee RDI: 0000000000000000 <4>[ 123.927882] RBP: 0000000000000000 R08: ffff88026e42b190 R09: 0000000091e0afb1 <4>[ 123.927884] R10: ffffc9000086fa78 R11: ffffffff81172490 R12: 0000000000000000 <4>[ 123.927886] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000 <4>[ 123.927894] ? find_get_pages_range_tag+0x340/0x340 <4>[ 123.927905] ? find_get_pages_range_tag+0x340/0x340 <4>[ 123.927913] find_get_entry+0x38/0x210 <4>[ 123.927918] ? find_get_pages_range_tag+0x340/0x340 <4>[ 123.927924] pagecache_get_page+0x2b/0x230 <4>[ 123.927932] ? __find_get_block+0xcb/0x3b0 <4>[ 123.927940] __find_get_block+0x1da/0x3b0 <4>[ 123.927949] __getblk_gfp+0x1f/0x2d0 <4>[ 123.927956] ? start_this_handle+0xff/0x440 <4>[ 123.927964] __ext4_get_inode_loc+0xff/0x500 <4>[ 123.927972] ? ext4_dirty_inode+0x3e/0x60 <4>[ 123.927977] ext4_reserve_inode_write+0x47/0xb0 <4>[ 123.927984] ext4_mark_inode_dirty+0x63/0x270 <4>[ 123.927992] ? rcu_read_lock_sched_held+0x6f/0x80 <4>[ 123.927999] ext4_dirty_inode+0x3e/0x60 <4>[ 123.928004] __mark_inode_dirty+0x67/0x690 <4>[ 123.928011] generic_update_time+0x73/0xc0 <4>[ 123.928017] ? current_time+0x2d/0x60 <4>[ 123.928022] file_update_time+0x90/0xe0 <4>[ 123.928030] __generic_file_write_iter+0x94/0x1b0 <4>[ 123.928040] ext4_file_write_iter+0x10f/0x3a0 <4>[ 123.928048] ? lock_acquire+0xaf/0x200 <4>[ 123.928054] __vfs_write+0xc5/0x130 <4>[ 123.928061] vfs_write+0xbd/0x1b0 <4>[ 123.928068] SyS_write+0x40/0xa0 <4>[ 123.928076] entry_SYSCALL_64_fastpath+0x1c/0x89 <4>[ 123.928080] RIP: 0033:0x7f2877fa468d <4>[ 123.928083] RSP: 002b:00007f28753565c0 EFLAGS: 00000293 ORIG_RAX: 0000000000000001 <4>[ 123.928087] RAX: ffffffffffffffda RBX: 000000000000005b RCX: 00007f2877fa468d <4>[ 123.928089] RDX: 000000000000099d RSI: 00007f2868003780 RDI: 0000000000000005 <4>[ 123.928091] RBP: 0000000000000005 R08: 0000559440ee3e30 R09: 0000000000000003 <4>[ 123.928094] R10: 0000559440ee2da0 R11: 0000000000000293 R12: 0000559440ee1a00 <4>[ 123.928096] R13: 0000000000000082 R14: 0000000000000000 R15: 0000559440ee4430 <4>[ 123.928103] Code: 00 00 00 c3 66 90 48 83 7f 20 00 74 08 48 39 7f 08 0f 95 c0 c3 31 c0 c3 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 48 83 7f 20 00 <74> 0c 48 8b 47 08 48 83 38 00 0f 95 c0 c3 31 c0 c3 66 2e 0f 1f <4>[ 123.928179] NMI backtrace for cpu 3 <4>[ 123.928187] CPU: 3 PID: 189 Comm: systemd-journal Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.928190] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 123.928200] RIP: 0010:mark_lock+0x5c/0x640 <4>[ 123.928203] RSP: 0018:ffff88027ed83d50 EFLAGS: 00000002 <4>[ 123.928209] RAX: 000000000000008f RBX: 0000000000000100 RCX: 0000000000000008 <4>[ 123.928212] RDX: 00000000000002cb RSI: ffff880271920918 RDI: ffff880271920040 <4>[ 123.928215] RBP: 0000000000000008 R08: 0000000000000001 R09: 0000000000000001 <4>[ 123.928219] R10: 0000000000000000 R11: ffffffff810c815a R12: ffff880271920918 <4>[ 123.928222] R13: ffff880271920040 R14: 0000000000000001 R15: 000000000000000c <4>[ 123.928227] FS: 00007f94eb80e8c0(0000) GS:ffff88027ed80000(0000) knlGS:0000000000000000 <4>[ 123.928231] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 123.928235] CR2: 0000000001998498 CR3: 00000002728c8002 CR4: 00000000003606e0 <4>[ 123.928236] Call Trace: <4>[ 123.928241] <IRQ> <4>[ 123.928257] __lock_acquire+0x34a/0x1b60 <4>[ 123.928275] ? lock_acquire+0xaf/0x200 <4>[ 123.928282] lock_acquire+0xaf/0x200 <4>[ 123.928292] ? swake_up+0xa/0x30 <4>[ 123.928302] _raw_spin_lock_irqsave+0x33/0x50 <4>[ 123.928310] ? swake_up+0xa/0x30 <4>[ 123.928317] swake_up+0xa/0x30 <4>[ 123.928329] rcu_process_callbacks+0xa1/0x6f0 <4>[ 123.928341] __do_softirq+0xc1/0x4aa <4>[ 123.928354] irq_exit+0xa4/0xb0 <4>[ 123.928361] smp_apic_timer_interrupt+0x90/0x2d0 <4>[ 123.928368] apic_timer_interrupt+0x93/0xa0 <4>[ 123.928371] </IRQ> <4>[ 123.928378] RIP: 0010:__follow_mount_rcu.isra.5+0x119/0x160 <4>[ 123.928382] RSP: 0018:ffffc900002dbc00 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff11 <4>[ 123.928388] RAX: ffff880271920040 RBX: ffffc900002dbde8 RCX: 0000000000000001 <4>[ 123.928391] RDX: 0000000000000007 RSI: ffffffff81d070c9 RDI: ffffffff81cb860e <4>[ 123.928395] RBP: ffffc900002dbc9c R08: ffff8802719208f0 R09: 00000000ca811012 <4>[ 123.928398] R10: 0000000000000000 R11: 0000000000000000 R12: ffffc900002dbca0 <4>[ 123.928402] R13: ffff880273e3a978 R14: 0000000000000202 R15: ffffc900002dbca8 <4>[ 123.928420] lookup_fast+0xb3/0x440 <4>[ 123.928430] walk_component+0x33/0x2c0 <4>[ 123.928441] link_path_walk+0x185/0x570 <4>[ 123.928447] ? path_init+0x4ae/0x6c0 <4>[ 123.928458] path_lookupat+0x81/0x1f0 <4>[ 123.928465] ? ___slab_alloc.constprop.30+0x152/0x3d0 <4>[ 123.928470] ? ___slab_alloc.constprop.30+0x152/0x3d0 <4>[ 123.928478] ? prepare_creds+0x1b/0xb0 <4>[ 123.928487] filename_lookup+0xa0/0x120 <4>[ 123.928497] ? getname_flags+0x2d/0x180 <4>[ 123.928506] ? rcu_read_lock_sched_held+0x6f/0x80 <4>[ 123.928512] ? kmem_cache_alloc+0x24a/0x2b0 <4>[ 123.928520] ? getname_flags+0x49/0x180 <4>[ 123.928531] ? SyS_faccessat+0xa2/0x200 <4>[ 123.928538] SyS_faccessat+0xa2/0x200 <4>[ 123.928548] do_syscall_64+0x59/0x1a0 <4>[ 123.928556] entry_SYSCALL64_slow_path+0x25/0x25 <4>[ 123.928563] RIP: 0033:0x7f94eaae4947 <4>[ 123.928566] RSP: 002b:00007ffd00f19298 EFLAGS: 00000246 ORIG_RAX: 0000000000000015 <4>[ 123.928572] RAX: ffffffffffffffda RBX: 00007ffd00f1c1a0 RCX: 00007f94eaae4947 <4>[ 123.928575] RDX: 00007f94eb5543e0 RSI: 0000000000000000 RDI: 0000557724830881 <4>[ 123.928578] RBP: 00007ffd00f192d0 R08: 0000000000002000 R09: 0000000000000000 <4>[ 123.928581] R10: 0000000000000080 R11: 0000000000000246 R12: 0000000000000000 <4>[ 123.928585] R13: 0000000000000000 R14: 00007ffd00f1c1a0 R15: 0000000000000009 <4>[ 123.928595] Code: 0f 84 89 00 00 00 31 c0 48 85 58 30 74 37 bb 01 00 00 00 48 83 c4 08 89 d8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f b7 c0 48 8d 14 80 <48> 8d 04 90 48 c1 e0 04 48 2d 50 01 00 00 48 05 20 fb da 82 48 <6>[ 123.928875] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.328 msecs <0>[ 123.929376] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 123.929493] CPU: 0 PID: 39 Comm: khungtaskd Not tainted 4.15.0-rc4-CI-CI_DRM_3568+ #1 <4>[ 123.929642] Hardware name: /NUC7i5BNB, BIOS BNKBL357.86A.0054.2017.1025.1822 10/25/2017 <4>[ 123.929805] Call Trace: <4>[ 123.929879] dump_stack+0x5f/0x86 <4>[ 123.929964] panic+0xcf/0x20d <4>[ 123.930075] watchdog+0x44a/0x5e0 <4>[ 123.930173] kthread+0xfb/0x130 <4>[ 123.930246] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.930337] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.930449] ret_from_fork+0x24/0x30 <0>[ 123.930607] Dumping ftrace buffer: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3570/shard-hsw3/igt@kms_frontbuffer_tracking@fbc-2p-primscrn-pri-indfb-draw-blt.html https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4083/shard-hsw5/igt@gem_exec_parse@basic-allocation.html https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3592/shard-hsw8/igt@gem_mmap_wc@write-read-distinct.html https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3591/shard-snb5/igt@gem_mmap_wc@write-read-distinct.html https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4113/shard-hsw4/igt@kms_frontbuffer_tracking@fbc-2p-primscrn-pri-shrfb-draw-pwrite.html run.log: running: igt/gem_tiled_swapping/non-threaded [41/76] skip: 20, pass: 20, fail: 1 / FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3596/shard-hsw4/17 : FAILURE CI_IGT_test runtime 253 seconds Rebooting shard-hsw4 last dmesg: <7>[ 60.901875] [IGT] gem_tiled_swapping: starting subtest non-threaded <6>[ 91.184616] Purging GPU memory, 50432 pages freed, 918 pages still pinned. <6>[ 96.742171] Purging GPU memory, 50176 pages freed, 918 pages still pinned. <7>[ 98.617512] [IGT] gem_tiled_swapping: exiting, ret=0 https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3600/shard-hsw2/igt@drv_suspend@fence-restore-tiled2untiled.html last test in run.log: running: igt/gem_tiled_swapping/non-threaded pstore: <14>[ 115.538394] [IGT] drv_suspend: executing <14>[ 115.565337] [IGT] drv_suspend: starting subtest fence-restore-tiled2untiled <6>[ 115.666004] PM: suspend entry (deep) <6>[ 115.666007] PM: Syncing filesystems ... done. <6>[ 115.687994] Freezing user space processes ... <3>[ 123.825063] INFO: task kswapd0:79 blocked for more than 60 seconds. <3>[ 123.825086] Tainted: G U 4.15.0-rc6-CI-CI_DRM_3600+ #1 <3>[ 123.825104] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6>[ 123.825123] kswapd0 D 0 79 2 0x80000000 <4>[ 123.825140] Call Trace: <4>[ 123.825148] ? __schedule+0x3c3/0xaf0 <4>[ 123.825156] schedule+0x37/0x90 <4>[ 123.825160] io_schedule+0xd/0x30 <4>[ 123.825164] __lock_page+0x107/0x130 <4>[ 123.825169] ? add_to_page_cache_lru+0xc0/0xc0 <4>[ 123.825176] deferred_split_scan+0x25a/0x2b0 <4>[ 123.825183] shrink_slab.part.17+0x201/0x5d0 <4>[ 123.825194] shrink_node+0x2fd/0x310 <4>[ 123.825201] kswapd+0x31c/0x910 <4>[ 123.825212] kthread+0xfb/0x130 <4>[ 123.825215] ? mem_cgroup_shrink_node+0x300/0x300 <4>[ 123.825217] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.825223] ret_from_fork+0x24/0x30 <4>[ 123.825231] <4>[ 123.825231] Showing all locks held in the system: <4>[ 123.825236] 2 locks held by khungtaskd/66: <4>[ 123.825240] #0: (rcu_read_lock){....}, at: [<00000000cdb621f1>] watchdog+0x9b/0x5e0 <4>[ 123.825251] #1: (tasklist_lock){.+.+}, at: [<000000001ce28407>] debug_show_all_locks+0x37/0x190 <4>[ 123.825262] 1 lock held by kswapd0/79: <4>[ 123.825264] #0: (shrinker_rwsem){++++}, at: [<0000000024cf4e12>] shrink_slab.part.17+0x46/0x5d0 <4>[ 123.825281] 4 locks held by rtcwake/1826: <4>[ 123.825282] #0: (sb_writers#5){.+.+}, at: [<00000000ec581cf0>] vfs_write+0x158/0x1b0 <4>[ 123.825292] #1: (&of->mutex){+.+.}, at: [<00000000b1aae5e2>] kernfs_fop_write+0xd9/0x1a0 <4>[ 123.825303] #2: (kn->count#132){.+.+}, at: [<00000000f959bbda>] kernfs_fop_write+0xe2/0x1a0 <4>[ 123.825313] #3: (pm_mutex){+.+.}, at: [<0000000013ef834e>] pm_suspend+0x9b/0x9d0 <4>[ 123.825323] <4>[ 123.825324] ============================================= <4>[ 123.825324] <4>[ 123.825327] NMI backtrace for cpu 0 <4>[ 123.825330] CPU: 0 PID: 66 Comm: khungtaskd Tainted: G U 4.15.0-rc6-CI-CI_DRM_3600+ #1 <4>[ 123.825332] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 123.825333] Call Trace: <4>[ 123.825337] dump_stack+0x5f/0x86 <4>[ 123.825340] nmi_cpu_backtrace+0xb4/0xc0 <4>[ 123.825346] ? lapic_can_unplug_cpu+0x90/0x90 <4>[ 123.825349] nmi_trigger_cpumask_backtrace+0xb8/0xf0 <4>[ 123.825353] watchdog+0x43e/0x5e0 <4>[ 123.825358] kthread+0xfb/0x130 <4>[ 123.825360] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.825362] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.825366] ret_from_fork+0x24/0x30 <6>[ 123.825375] Sending NMI from CPU 0 to CPUs 1-7: <4>[ 123.825383] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825394] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825397] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825400] NMI backtrace for cpu 5 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825403] NMI backtrace for cpu 1 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825407] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120 <4>[ 123.825410] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120 <0>[ 123.826383] Kernel panic - not syncing: hung_task: blocked tasks <4>[ 123.826400] CPU: 0 PID: 66 Comm: khungtaskd Tainted: G U 4.15.0-rc6-CI-CI_DRM_3600+ #1 <4>[ 123.826421] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4>[ 123.826439] Call Trace: <4>[ 123.826448] dump_stack+0x5f/0x86 <4>[ 123.826459] panic+0xcf/0x20d <4>[ 123.826474] watchdog+0x44a/0x5e0 <4>[ 123.826486] kthread+0xfb/0x130 <4>[ 123.826496] ? reset_hung_task_detector+0x10/0x10 <4>[ 123.826508] ? _kthread_create_on_node+0x30/0x30 <4>[ 123.826522] ret_from_fork+0x24/0x30 <0>[ 123.826922] Dumping ftrace buffer: <0>[ 123.826995] (ftrace buffer empty) <0>[ 123.827006] Kernel Offset: disabled *** Bug 104009 has been marked as a duplicate of this bug. *** *** Bug 103525 has been marked as a duplicate of this bug. *** https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4133/shard-snb6/igt@prime_self_import@reimport-vs-gem_close-race.html run.log doesn't match results: run.log: running: igt/gem_tiled_swapping/non-threaded [34/76] skip: 18, pass: 16 - FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3624/shard-snb6/12 : FAILURE CI_IGT_test runtime 212 seconds Rebooting shard-snb6 dmesg: <7>[ 105.739615] [IGT] gem_tiled_swapping: starting subtest non-threaded ... <7>[ 181.532388] [IGT] gem_flink_basic: starting subtest flink-lifetime <7>[ 181.532706] [IGT] gem_flink_basic: exiting, ret=0 <6>[ 181.542119] Console: switching to colour frame buffer device 128x48 https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3625/shard-snb6/igt@gem_ctx_switch@basic-default-heavy.html run.log doesn't match results last test is igt@gem_tiled_swapping@non-threaded: running: igt/gem_tiled_swapping/non-threaded [34/76] skip: 18, pass: 16 - FATAL: command execution failed last dmesg: <7>[ 181.361294] [IGT] kms_flip: starting subtest 2x-busy-flip <7>[ 181.366829] [IGT] kms_flip: exiting, ret=77 <6>[ 181.394551] Console: switching to colour frame buffer device 128x48 <6>[ 181.495430] Console: switching to colour dummy device 80x25 <7>[ 181.495480] [IGT] gem_ctx_switch: executing https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3629/shard-hsw5/igt@kms_flip@dpms-off-confusion-interruptible.html run.log doesn't match result last test in run.log: running: igt/gem_tiled_swapping/non-threaded [07/77] skip: 2, pass: 5 \ FATAL: command execution failed last dmesg: <7>[ 169.549258] [IGT] kms_frontbuffer_tracking: starting subtest psr-2p-scndscrn-pri-indfb-draw-mmap-gtt <7>[ 169.549593] [IGT] kms_frontbuffer_tracking: exiting, ret=77 https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3631/shard-hsw3/igt@gem_exec_flush@basic-wb-set-default.html [07/77] skip: 2, pass: 5 - running: igt/gem_tiled_swapping/non-threaded [07/77] skip: 2, pass: 5 \ FATAL: command execution failed https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4149/shard-snb6/igt@kms_cursor_legacy@pipe-b-forked-bo.html last test in run.log: running: igt/gem_tiled_swapping/non-threaded from dmesg: <7>[ 105.736234] [IGT] gem_tiled_swapping: starting subtest non-threaded ... <7>[ 165.295673] [IGT] kms_cursor_legacy: starting subtest pipe-B-forked-bo https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4152/shard-glkb2/igt@kms_plane@plane-panning-bottom-right-suspend-pipe-d-planes.html run.log: pass: igt/gem_tiled_swapping/non-threaded [53/77] skip: 15, pass: 32, fail: 6 | running: igt/kms_plane/plane-panning-bottom-right-suspend-pipe-d-planes [53/77] skip: 15, pass: 32, fail: 6 / FATAL: command execution failed java.io.EOFException last dmesg: <7>[ 342.794006] [IGT] gem_tiled_swapping: executing <4>[ 342.941191] hpet1: lost 7160 rtc interrupts <4>[ 343.833082] hpet1: lost 7161 rtc interrupts <4>[ 344.722754] hpet1: lost 7161 rtc interrupts <4>[ 345.643445] hpet1: lost 7161 rtc interrupts <4>[ 346.540868] hpet1: lost 7161 rtc interrupts <7>[ 346.829679] [IGT] gem_tiled_swapping: starting subtest non-threaded <4>[ 347.439913] hpet1: lost 7160 rtc interrupts <4>[ 348.328927] hpet1: lost 7161 rtc interrupts <4>[ 349.218968] hpet1: lost 7160 rtc interrupts <4>[ 350.114868] hpet1: lost 7160 rtc interrupts <4>[ 350.982943] hpet1: lost 7161 rtc interrupts <4>[ 351.870914] hpet1: lost 7161 rtc interrupts <4>[ 352.758969] hpet1: lost 7160 rtc interrupts <4>[ 353.660559] hpet1: lost 7161 rtc interrupts <4>[ 354.575417] hpet1: lost 7161 rtc interrupts <4>[ 355.490256] hpet1: lost 7161 rtc interrupts <4>[ 356.404387] hpet1: lost 7161 rtc interrupts <4>[ 357.318114] hpet1: lost 7161 rtc interrupts <4>[ 358.230353] hpet1: lost 7161 rtc interrupts <4>[ 359.117455] hpet1: lost 7161 rtc interrupts <4>[ 359.989715] hpet1: lost 7161 rtc interrupts <4>[ 360.880813] hpet1: lost 7161 rtc interrupts <4>[ 361.771852] hpet1: lost 7160 rtc interrupts <4>[ 362.663542] hpet1: lost 7161 rtc interrupts <4>[ 363.554807] hpet1: lost 7161 rtc interrupts <4>[ 364.445222] hpet1: lost 7161 rtc interrupts <4>[ 365.336485] hpet1: lost 7161 rtc interrupts <7>[ 382.277695] [IGT] gem_tiled_swapping: exiting, ret=0 pstore has a lot of: <0>[ 743.048761] gem_pers-1647 3..s1 238987857us : execlists_submission_tasklet: bcs0 in[0]: ctx=2.2, seqno=2f1 and then just backtrace of sysrq trigger. https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4152/shard-apl3/igt@pm_rps@reset.html last in run.log: running: igt/gem_tiled_swapping/non-threaded from dmesg: <4>[ 292.845498] hpet1: lost 7160 rtc interrupts <7>[ 293.200218] [IGT] gem_tiled_swapping: starting subtest non-threaded <4>[ 293.760511] hpet1: lost 7161 rtc interrupts ... <7>[ 367.284472] [drm:intel_dp_read_dpcd [i915]] DPCD: 11 0a 82 01 00 03 01 01 02 00 00 00 00 00 00 <7>[ 367.630311] [IGT] pm_rps: executing pstore starts with: <4>[ 369.811603] 1 lock held by dmesg/1056: <4>[ 369.811606] #0: (&user->lock){+.+.}, at: [<000000000c0f2971>] devkmsg_read+0x35/0x2f0 so maybe some deadlocky thing, then there is ftrace. https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3652/shard-hsw4/igt@gem_wait@write-wait-render.html last in run.log: running: igt/gem_tiled_swapping/non-threaded from dmesg: <7>[ 90.805782] [IGT] gem_tiled_swapping: starting subtest non-threaded <7>[ 128.124226] [IGT] gem_tiled_swapping: exiting, ret=0 ... <7>[ 184.200292] [IGT] perf: executing <7>[ 184.214368] [IGT] perf: starting subtest invalid-open-flags <7>[ 184.214467] [IGT] perf: exiting, ret=0 pstore say: <3>[ 185.311947] INFO: task kswapd0:80 blocked for more than 60 seconds. so kswap has been blocked 60 seconds, i.e. when gem_tiled_swapping@non-threaded was run. https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4161/shard-hsw7/igt@gem_cpu_reloc@full.html last test in run.log: running: igt/gem_tiled_swapping/non-threaded from dmesg: <7>[ 48.618066] [IGT] gem_tiled_swapping: starting subtest non-threaded ... <7>[ 89.998332] [IGT] gem_cpu_reloc: executing <7>[ 90.017340] [IGT] gem_cpu_reloc: starting subtest full *** Bug 104479 has been marked as a duplicate of this bug. *** Last occurrence of this issue appear to be here: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3663/shard-hsw8/igt@kms_flip@flip-vs-panning.html We are now at CI_DRM_3671. I will keep monitoring, I have no idea of what that may have changed that could have fixed this issue. went through all shard run.logs CI_DRM_3671 - CI_DRM_3677, still no issues on shards with igt@gem_tiled_swapping@non-threaded in them. Went trough all run.log CI_DRM_3677 - CI_DRM_3684, only one incomplete where igt@gem_tiled_swapping@non-threaded was run before: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3684/shard-kbl3/igt@gem_tiled_swapping@non-threaded.html However, <7>[ 38.122175] [IGT] gem_tiled_swapping: starting subtest non-threaded last test in run.log is: igt/drv_suspend/debugfs-reader-hibernate <7>[ 154.190154] [IGT] drv_suspend: starting subtest debugfs-reader-hibernate so more than 60 seconds rules out the previous non-threaded issue. The "Last seen" calculation in cibuglog is not suitable for bugs with big impact, and KBL hitting Link training on previously affected subtests. I will close this. commit fa41b900c30b45fab03783724932dc30cd46a6be Author: Kirill A. Shutemov <kirill.shutemov@linux.intel.com> Date: Thu Mar 22 16:17:31 2018 -0700 mm/thp: do not wait for lock_page() in deferred_split_scan() deferred_split_scan() gets called from reclaim path. Waiting for page lock may lead to deadlock there. Replace lock_page() with trylock_page() and skip the page if we failed to lock it. We will get to the page on the next scan. Link: http://lkml.kernel.org/r/20180315150747.31945-1-kirill.shutemov@linux. intel.com Fixes: 9a982250f773 ("thp: introduce deferred_split_huge_page()") Signed-off-by: Kirill A. Shutemov <kirill.shutemov@linux.intel.com> Acked-by: Michal Hocko <mhocko@suse.com> Cc: <stable@vger.kernel.org> Signed-off-by: Andrew Morton <akpm@linux-foundation.org> Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org> |
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.