Bug 110260 - [CI][SHARDS] igt@gem_exec_big@single - dmesg-fail / incomplete - gem_exec_big: page allocation failure
Summary: [CI][SHARDS] igt@gem_exec_big@single - dmesg-fail / incomplete - gem_exec_big...
Status: RESOLVED WORKSFORME
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: XOrg git
Hardware: Other All
: high normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
Depends on:
Blocks:
 
Reported: 2019-03-27 15:58 UTC by Martin Peres
Modified: 2019-04-02 07:56 UTC (History)
1 user (show)

See Also:
i915 platform: ICL
i915 features: GEM/Other

Attachments

Description Martin Peres 2019-03-27 15:58:45 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5818/shard-iclb3/igt@gem_exec_big@single.html

<6> [34.872999] Console: switching to colour dummy device 80x25
<6> [34.873100] [IGT] gem_exec_big: executing
<6> [34.900697] [IGT] gem_exec_big: starting subtest single
<6> [34.901109] gem_exec_big (1123): drop_caches: 4
<4> [78.233060] gem_exec_big: page allocation failure: order:0, mode:0x104cd2(GFP_HIGHUSER|__GFP_RETRY_MAYFAIL|__GFP_RECLAIMABLE), nodemask=(null)
<4> [78.233077] CPU: 5 PID: 1123 Comm: gem_exec_big Tainted: G     U            5.1.0-rc2-CI-CI_DRM_5818+ #1
<4> [78.233079] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP, BIOS ICLSFWR1.R00.3087.A00.1902250334 02/25/2019
<4> [78.233080] Call Trace:
<4> [78.233086]  dump_stack+0x67/0x9b
<4> [78.233089]  warn_alloc+0xfa/0x180
<4> [78.233095]  ? __mutex_unlock_slowpath+0x46/0x2b0
<4> [78.233099]  __alloc_pages_nodemask+0xd49/0x1120
<4> [78.233109]  __read_swap_cache_async+0x131/0x1d0
<4> [78.233113]  swap_cluster_readahead+0x1ae/0x280
<4> [78.233120]  ? shmem_swapin+0x7b/0xa0
<4> [78.233122]  shmem_swapin+0x7b/0xa0
<4> [78.233126]  ? find_get_entry+0x1b5/0x2f0
<4> [78.233134]  shmem_swapin_page+0x5a4/0x7c0
<4> [78.233140]  shmem_getpage_gfp.isra.8+0x2bb/0x860
<4> [78.233147]  shmem_read_mapping_page_gfp+0x3e/0x70
<4> [78.233185]  i915_gem_object_get_pages_gtt+0x212/0x6d0 [i915]
<4> [78.233214]  ? __i915_gem_object_get_pages+0x18/0xb0 [i915]
<4> [78.233242]  ____i915_gem_object_get_pages+0x1d/0xa0 [i915]
<4> [78.233265]  __i915_gem_object_get_pages+0x59/0xb0 [i915]
<4> [78.233292]  __i915_vma_do_pin+0x9d5/0xdc0 [i915]
<4> [78.233318]  eb_lookup_vmas+0x8d4/0x1250 [i915]
<4> [78.233344]  i915_gem_do_execbuffer+0x653/0x1af0 [i915]
<4> [78.233353]  ? __lock_acquire+0x4a0/0x1590
<4> [78.233359]  ? __might_fault+0x38/0x90
<4> [78.233383]  ? i915_gem_execbuffer_ioctl+0x300/0x300 [i915]
<4> [78.233404]  i915_gem_execbuffer2_ioctl+0x11b/0x420 [i915]
<4> [78.233425]  ? i915_gem_execbuffer_ioctl+0x300/0x300 [i915]
<4> [78.233429]  drm_ioctl_kernel+0x83/0xf0
<4> [78.233433]  drm_ioctl+0x2f3/0x3b0
<4> [78.233453]  ? i915_gem_execbuffer_ioctl+0x300/0x300 [i915]
<4> [78.233459]  ? _raw_spin_unlock_irq+0x24/0x50
<4> [78.233461]  ? lockdep_hardirqs_on+0xe3/0x1b0
<4> [78.233465]  do_vfs_ioctl+0xa0/0x6e0
<4> [78.233468]  ? __schedule+0x375/0xb40
<4> [78.233472]  ksys_ioctl+0x35/0x60
<4> [78.233475]  __x64_sys_ioctl+0x11/0x20
<4> [78.233477]  do_syscall_64+0x55/0x190
<4> [78.233480]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [78.233482] RIP: 0033:0x7fb57ada35d7
<4> [78.233487] Code: Bad RIP value.
<4> [78.233489] RSP: 002b:00007fffea5f0878 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [78.233491] RAX: ffffffffffffffda RBX: 0000000010000000 RCX: 00007fb57ada35d7
<4> [78.233492] RDX: 00007fffea5f0970 RSI: 0000000040406469 RDI: 0000000000000005
<4> [78.233493] RBP: 00007fffea5f0970 R08: 00007fb1ac887010 R09: 0000000000000000
<4> [78.233495] R10: 0000000000000054 R11: 0000000000000246 R12: 0000000040406469
<4> [78.233496] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
<4> [78.233530] Mem-Info:
<4> [78.233533] active_anon:1414305 inactive_anon:16896 isolated_anon:512
 active_file:81 inactive_file:64 isolated_file:0
 unevictable:2506036 dirty:0 writeback:4 unstable:0
 slab_reclaimable:20612 slab_unreclaimable:18287
 mapped:3865987 shmem:3882628 pagetables:9002 bounce:0
 free:35759 free_pcp:0 free_cma:0
<4> [78.233536] Node 0 active_anon:5657220kB inactive_anon:67584kB active_file:324kB inactive_file:256kB unevictable:10024144kB isolated(anon):2048kB isolated(file):0kB mapped:15463948kB dirty:0kB writeback:16kB shmem:15530512kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 124928kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
<4> [78.233538] DMA free:15876kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15876kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [78.233540] lowmem_reserve[]: 0 964 15788 15788
<4> [78.233544] DMA32 free:63328kB min:4124kB low:5152kB high:6180kB active_anon:987692kB inactive_anon:0kB active_file:8kB inactive_file:0kB unevictable:24kB writepending:0kB present:1104624kB managed:1056916kB mlocked:0kB kernel_stack:0kB pagetables:1932kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [78.233545] lowmem_reserve[]: 0 0 14823 14823
<4> [78.233549] Normal free:63832kB min:63392kB low:79240kB high:95088kB active_anon:4670296kB inactive_anon:65536kB active_file:608kB inactive_file:544kB unevictable:10023604kB writepending:16kB present:15470592kB managed:15179776kB mlocked:0kB kernel_stack:3392kB pagetables:34076kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [78.233550] lowmem_reserve[]: 0 0 0 0
<4> [78.233552] DMA: 1*4kB (U) 0*8kB 2*16kB (U) 1*32kB (U) 1*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15876kB
<4> [78.233560] DMA32: 5*4kB (UM) 6*8kB (UE) 9*16kB (UME) 8*32kB (UME) 14*64kB (UME) 11*128kB (UME) 11*256kB (UME) 7*512kB (M) 7*1024kB (UM) 1*2048kB (E) 11*4096kB (M) = 63444kB
<4> [78.233568] Normal: 1170*4kB (UME) 537*8kB (UME) 297*16kB (UME) 92*32kB (UME) 76*64kB (UME) 142*128kB (M) 64*256kB (M) 16*512kB (ME) 0*1024kB 0*2048kB 0*4096kB = 64288kB
<6> [78.233576] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
<4> [78.233577] 3902849 total pagecache pages
<4> [78.233580] 20011 pages in swap cache
<4> [78.233581] Swap cache stats: add 113228, delete 93228, find 18319/22700
<4> [78.233583] Free swap  = 1801724kB
<4> [78.233584] Total swap = 2097148kB
<4> [78.233585] 4147802 pages RAM
<4> [78.233586] 0 pages HighMem/MovableOnly
<4> [78.233587] 84660 pages reserved
<4> [81.916503] java invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
<4> [81.916524] CPU: 5 PID: 976 Comm: java Tainted: G     U            5.1.0-rc2-CI-CI_DRM_5818+ #1
<4> [81.916527] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP, BIOS ICLSFWR1.R00.3087.A00.1902250334 02/25/2019
<4> [81.916528] Call Trace:
<4> [81.916534]  dump_stack+0x67/0x9b
<4> [81.916539]  dump_header+0x52/0x610
<4> [81.916542]  ? _raw_spin_unlock_irqrestore+0x4c/0x60
<4> [81.916545]  ? _raw_spin_unlock_irqrestore+0x4c/0x60
<4> [81.916548]  ? lockdep_hardirqs_on+0xe3/0x1b0
<4> [81.916551]  ? _raw_spin_unlock_irqrestore+0x39/0x60
<4> [81.916556]  oom_kill_process+0x175/0x210
<4> [81.916561]  out_of_memory+0x107/0x3a0
<4> [81.916565]  __alloc_pages_nodemask+0xd0e/0x1120
<4> [81.916579]  pagecache_get_page+0xdf/0x220
<4> [81.916585]  filemap_fault+0x44d/0x820
<4> [81.916592]  ext4_filemap_fault+0x27/0x40
<4> [81.916605]  __do_fault+0x2c/0xb0
<4> [81.916609]  __handle_mm_fault+0x9a6/0xfc0
<4> [81.916619]  handle_mm_fault+0x196/0x3a0
<4> [81.916624]  __do_page_fault+0x248/0x4f0
<4> [81.916630]  ? page_fault+0x8/0x30
<4> [81.916633]  page_fault+0x1e/0x30
<4> [81.916636] RIP: 0033:0x7f0746565fa0
<4> [81.916641] Code: Bad RIP value.
<4> [81.916644] RSP: 002b:00007f072c5c1b78 EFLAGS: 00010206
<4> [81.916646] RAX: 00007f0746565fa0 RBX: 00007f07401c8e00 RCX: 0000000000000018
<4> [81.916648] RDX: 00000e148869c3fa RSI: 00007f072c5c1ba0 RDI: 00007f07401c8e28
<4> [81.916650] RBP: 00007f072c5c1bf0 R08: 00007ffd175eb0b0 R09: 00007ffd175eb080
<4> [81.916651] R10: 0000000000026fa2 R11: 0000000000000051 R12: 0000000000000052
<4> [81.916653] R13: 00007f07401c8e28 R14: 00007f07401c8000 R15: 00007f07400078c0
<4> [81.916662] Mem-Info:
<4> [81.916667] active_anon:25299 inactive_anon:27136 isolated_anon:2048
 active_file:40 inactive_file:1 isolated_file:0
 unevictable:3883393 dirty:0 writeback:0 unstable:0
 slab_reclaimable:20613 slab_unreclaimable:18317
 mapped:3865950 shmem:3883393 pagetables:9002 bounce:0
 free:35498 free_pcp:0 free_cma:0
<4> [81.916671] Node 0 active_anon:101196kB inactive_anon:108544kB active_file:160kB inactive_file:4kB unevictable:15533572kB isolated(anon):8192kB isolated(file):0kB mapped:15463800kB dirty:0kB writeback:0kB shmem:15533572kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 77824kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
<4> [81.916675] DMA free:15876kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15876kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [81.916676] lowmem_reserve[]: 0 964 15788 15788
<4> [81.916683] DMA32 free:63320kB min:4124kB low:5152kB high:6180kB active_anon:6684kB inactive_anon:0kB active_file:0kB inactive_file:12kB unevictable:981032kB writepending:0kB present:1104624kB managed:1056916kB mlocked:0kB kernel_stack:0kB pagetables:1932kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [81.916685] lowmem_reserve[]: 0 0 14823 14823
<4> [81.916690] Normal free:62796kB min:63392kB low:79240kB high:95088kB active_anon:94512kB inactive_anon:104448kB active_file:0kB inactive_file:568kB unevictable:14552540kB writepending:0kB present:15470592kB managed:15179776kB mlocked:0kB kernel_stack:3392kB pagetables:34076kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
<4> [81.916692] lowmem_reserve[]: 0 0 0 0
<4> [81.916696] DMA: 1*4kB (U) 0*8kB 2*16kB (U) 1*32kB (U) 1*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15876kB
<4> [81.916714] DMA32: 3*4kB (UM) 7*8kB (UME) 9*16kB (UME) 8*32kB (UME) 14*64kB (UME) 11*128kB (UME) 11*256kB (UME) 7*512kB (M) 7*1024kB (UM) 1*2048kB (E) 11*4096kB (M) = 63444kB
<4> [81.916727] Normal: 965*4kB (UME) 486*8kB (UME) 289*16kB (UM) 158*32kB (UME) 79*64kB (UM) 137*128kB (UM) 64*256kB (UME) 15*512kB (UM) 0*1024kB 0*2048kB 0*4096kB = 64084kB
<6> [81.916740] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
<4> [81.916742] 3915352 total pagecache pages
<4> [81.916745] 31839 pages in swap cache
<4> [81.916747] Swap cache stats: add 126863, delete 95037, find 18946/23639
<4> [81.916749] Free swap  = 1753596kB
<4> [81.916751] Total swap = 2097148kB
<4> [81.916753] 4147802 pages RAM
<4> [81.916754] 0 pages HighMem/MovableOnly
<4> [81.916756] 84660 pages reserved
<6> [81.916758] Tasks state (memory values in pages):
<6> [81.916760] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
<6> [81.916847] [    305]     0   305    23690        1   196608      168             0 systemd-journal
<6> [81.916918] [    323]     0   323    11102        1   118784      507         -1000 systemd-udevd
<6> [81.916922] [    518]   101   518    17652        0   176128      163             0 systemd-resolve
<6> [81.916935] [    531]   102   531    65758        9   163840      358             0 rsyslogd
<6> [81.916938] [    532]   103   532    12575        1   147456      234          -900 dbus-daemon
<6> [81.916942] [    556]     0   556    17647        1   180224      184             0 systemd-logind
<6> [81.916946] [    558]     0   558    44726        1   225280     1990             0 networkd-dispat
<6> [81.916950] [    561]     0   561     1137        0    57344       41             0 acpid
<6> [81.916954] [    567]     0   567    27626       22   122880       69             0 irqbalance
<6> [81.916958] [    570]     0   570     2478        0    57344       32             0 rngd
<6> [81.916962] [    634]     0   634   159642       10   454656      709             0 NetworkManager
<6> [81.916966] [    701]     0   701    18073        0   184320      188         -1000 sshd
<6> [81.916970] [    703]     0   703    72218        0   200704      217             0 polkitd
<6> [81.916973] [    709]     0   709     6126        0    81920       38             0 agetty
<6> [81.916977] [    724]     0   724     6413        1    90112      305             0 dhclient
<6> [81.916981] [    873]     0   873    26430        1   245760      246             0 sshd
<6> [81.916984] [    878]  1000   878    19153        1   188416      273             0 systemd
<6> [81.916988] [    881]  1000   881    28470        0   258048      595             0 (sd-pam)
<6> [81.916992] [    892]  1000   892   151775        0   155648      847             0 ubuntu-report
<6> [81.916996] [    928]  1000   928    27039       33   249856      259             0 sshd
<6> [81.917000] [    964]  1000   964  2069822     3795   860160    34711             0 java
<6> [81.917004] [   1002]  1000  1002     5302        1    81920       71             0 bash
<6> [81.917008] [   1080]     0  1080    18483        1   180224      119             0 sudo
<6> [81.917011] [   1085]     0  1085     2478        0    65536       31             0 rngd
<6> [81.917015] [   1107]  1000  1107     6097       15    90112       23             0 dmesg
<6> [81.917019] [   1110]     0  1110    18483        1   180224      120             0 sudo
<6> [81.917022] [   1114]     0  1114    50696        7   405504      427             0 igt_runner
<6> [81.917026] [   1123]     0  1123  3992924  3885529 32026624    11378          1000 gem_exec_big
<6> [81.917029] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),global_oom,task_memcg=/,task=gem_exec_big,pid=1123,uid=0
<3> [81.917278] Out of memory: Killed process 1123 (gem_exec_big) total-vm:15971696kB, anon-rss:78464kB, file-rss:0kB, shmem-rss:15463652kB
<6> [81.942894] oom_reaper: reaped process 1123 (gem_exec_big), now anon-rss:0kB, file-rss:0kB, shmem-rss:15463652kB
<6> [87.120729] gem_exec_big (1123) used greatest stack depth: 9832 bytes left
Comment 1 Chris Wilson 2019-03-27 17:07:29 UTC 
It's the same old page allocation failure under the slightest bit of file system activity (this case seems to be caused by the Java process continuing to allocate while igt believes it can use all available memory being the sole task). Swept under the carpet (go look at the other page allocation failures) because ignorance is bliss.
Comment 3 CI Bug Log 2019-03-28 11:48:54 UTC 
A CI Bug Log filter associated to this bug has been updated:

{- APL ICL: igt@gem_exec_big@single - dmesg-fail / incomplete - gem_exec_big: page allocation failure -}
{+ APL ICL: igt@gem_exec_big@single - dmesg-fail / incomplete - Out of memory +}

New failures caught by the filter:

* https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4904/shard-iclb8/igt@gem_exec_big@single.html
* https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5816/shard-iclb4/igt@gem_exec_big@single.html
* https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5817/shard-iclb3/igt@gem_exec_big@single.html
Comment 4 CI Bug Log 2019-04-02 07:56:37 UTC 
The CI Bug Log issue associated to this bug has been archived.

New failures matching the above filters will not be associated to this bug anymore.

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.