dell / libsmbios

library for interacting with Dell SMBIOS tables
Other
192 stars 39 forks source link

page allocation failure #63

Open leezu opened 6 years ago

leezu commented 6 years ago

Running smbios-thermal-ctl sometimes fails, leading to the following output in dmesg.

[70050.804059] smbios-thermal-: page allocation failure: order:4, mode:0x6040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)
[70050.804062] smbios-thermal- cpuset=/ mems_allowed=0
[70050.804066] CPU: 1 PID: 22706 Comm: smbios-thermal- Not tainted 4.18.6-gentoo #2
[70050.804067] Hardware name: Dell Inc. XPS 13 9360/06CC14, BIOS 2.9.0 07/09/2018
[70050.804068] Call Trace:
[70050.804074]  dump_stack+0x5d/0x79
[70050.804077]  warn_alloc+0xd2/0x165
[70050.804079]  __alloc_pages_nodemask+0x8f6/0x963
[70050.804082]  ? down_timeout+0x3c/0x43
[70050.804084]  cache_alloc_refill+0x27f/0x7e3
[70050.804086]  __kmalloc+0xb8/0x107
[70050.804089]  acpi_ut_initialize_buffer+0x53/0x83
[70050.804092]  acpi_evaluate_object+0x21b/0x285
[70050.804096]  wmidev_evaluate_method+0xe7/0x102 [wmi]
[70050.804100]  run_smbios_call+0x59/0x9e [dell_smbios]
[70050.804102]  dell_smbios_wmi_filter+0x85/0xac [dell_smbios]
[70050.804104]  wmi_ioctl+0xe7/0x12f [wmi]
[70050.804107]  vfs_ioctl+0x19/0x26
[70050.804108]  do_vfs_ioctl+0x518/0x540
[70050.804110]  ksys_ioctl+0x39/0x58
[70050.804112]  __x64_sys_ioctl+0x11/0x14
[70050.804114]  do_syscall_64+0x50/0xdf
[70050.804116]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[70050.804118] RIP: 0033:0x7feca502b8c7
[70050.804118] Code: 00 00 00 75 0c 48 c7 c0 ff ff ff ff 48 83 c4 18 c3 e8 6d df 01 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 91 55 2c 00 f7 d8 64 89 01 48
[70050.804136] RSP: 002b:00007ffdd8be90f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[70050.804137] RAX: ffffffffffffffda RBX: 000055698d1aa010 RCX: 00007feca502b8c7
[70050.804138] RDX: 000055698d1aa010 RSI: 00000000c0345700 RDI: 0000000000000003
[70050.804139] RBP: 0000000000008008 R08: 000055698d1aa010 R09: 00007feca52f23c0
[70050.804140] R10: 0000000000000000 R11: 0000000000000246 R12: 00007feca318c580
[70050.804141] R13: 000055698d196980 R14: 00000000fffffffb R15: 0000000000000003
[70050.804142] Mem-Info:
[70050.804145] active_anon:1000976 inactive_anon:372917 isolated_anon:0
                active_file:1552544 inactive_file:809658 isolated_file:0
                unevictable:73 dirty:457 writeback:0 unstable:0
                slab_reclaimable:140915 slab_unreclaimable:61972
                mapped:281375 shmem:430602 pagetables:19814 bounce:0
                free:39510 free_pcp:0 free_cma:0
[70050.804149] Node 0 active_anon:4003904kB inactive_anon:1491668kB active_file:6210176kB inactive_file:3238632kB unevictable:292kB isolated(anon):0kB isolated(file):0kB mapped:1125500kB dirty:1828kB writeback:0kB shmem:1722408kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[70050.804152] DMA free:15900kB min:12kB low:24kB high:36kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15984kB managed:15900kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[70050.804153] lowmem_reserve[]: 0 1720 15616 15616
[70050.804157] DMA32 free:112380kB min:1760kB low:3520kB high:5280kB active_anon:261032kB inactive_anon:96820kB active_file:752080kB inactive_file:435408kB unevictable:0kB writepending:308kB present:1827068kB managed:1761404kB mlocked:0kB kernel_stack:80kB pagetables:1552kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[70050.804158] lowmem_reserve[]: 0 0 13896 13896
[70050.804162] Normal free:29760kB min:14220kB low:28448kB high:42676kB active_anon:3742760kB inactive_anon:1394972kB active_file:5458124kB inactive_file:2803332kB unevictable:292kB writepending:1520kB present:14655488kB managed:14351212kB mlocked:292kB kernel_stack:16112kB pagetables:77704kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[70050.804163] lowmem_reserve[]: 0 0 0 0
[70050.804165] DMA: 1*4kB (U) 1*8kB (U) 1*16kB (U) 2*32kB (U) 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15900kB
[70050.804171] DMA32: 186*4kB (UMEH) 4288*8kB (UMEH) 4586*16kB (UEH) 105*32kB (UEH) 13*64kB (H) 2*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 112872kB
[70050.804178] Normal: 784*4kB (UMEH) 3325*8kB (UMEH) 32*16kB (UEH) 11*32kB (EH) 4*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 30856kB
[70050.804183] 2801633 total pagecache pages
[70050.804186] 8772 pages in swap cache
[70050.804187] Swap cache stats: add 1296796, delete 1288021, find 210141/251324
[70050.804188] Free swap  = 19569420kB
[70050.804189] Total swap = 20971516kB
[70050.804190] 4124635 pages RAM
[70050.804190] 0 pages HighMem/MovableOnly
[70050.804191] 92506 pages reserved
superm1 commented 6 years ago

Can you please try this kernel patch to see if it helps? http://git.infradead.org/linux-platform-drivers-x86.git/commit/affab51082174f60ef71ced8ab5fbe71f00e9ae3

leezu commented 6 years ago

Running while sudo smbios-thermal-ctl -i; do :; done for a minute after applying the patch, I could not observe the error again. Previously it would occur after around ~5 seconds of above while loop.

Thanks for the quick fix.

leezu commented 6 years ago

It seems the error disappearing was rather an artefact of rebooting the system due to replacing the kernel. Trying again a few hours later, the problem reappears:



[26835.161713] smbios-thermal-: page allocation failure: order:4, mode:0x6040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)
[26835.161716] smbios-thermal- cpuset=/ mems_allowed=0
[26835.161721] CPU: 3 PID: 2091 Comm: smbios-thermal- Not tainted 4.18.7-gentoo #4
[26835.161722] Hardware name: Dell Inc. XPS 13 9360/06CC14, BIOS 2.9.0 07/09/2018
[26835.161723] Call Trace:
[26835.161729]  dump_stack+0x5d/0x79
[26835.161733]  warn_alloc+0xd2/0x165
[26835.161735]  __alloc_pages_nodemask+0x8f6/0x963
[26835.161738]  ? down_timeout+0x3c/0x43
[26835.161740]  cache_alloc_refill+0x27f/0x7e3
[26835.161742]  __kmalloc+0xb8/0x107
[26835.161745]  acpi_ut_initialize_buffer+0x53/0x83
[26835.161747]  acpi_evaluate_object+0x21b/0x285
[26835.161752]  wmidev_evaluate_method+0xe7/0x102 [wmi]
[26835.161756]  run_smbios_call+0x59/0xa8 [dell_smbios]
[26835.161758]  dell_smbios_wmi_filter+0x85/0xac [dell_smbios]
[26835.161760]  wmi_ioctl+0xe7/0x12f [wmi]
[26835.161763]  vfs_ioctl+0x19/0x26
[26835.161765]  do_vfs_ioctl+0x518/0x540
[26835.161767]  ksys_ioctl+0x39/0x58
[26835.161768]  __x64_sys_ioctl+0x11/0x14
[26835.161770]  do_syscall_64+0x88/0x14e
[26835.161773]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[26835.161775] RIP: 0033:0x7f8ac3ac18c7
[26835.161776] Code: 00 00 00 75 0c 48 c7 c0 ff ff ff ff 48 83 c4 18 c3 e8 6d df 01 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 91 55 2c 00 f7 d8 64 89 01 48
[26835.161793] RSP: 002b:00007ffe912ee5f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[26835.161794] RAX: ffffffffffffffda RBX: 000055f3d58a8010 RCX: 00007f8ac3ac18c7
[26835.161795] RDX: 000055f3d58a8010 RSI: 00000000c0345700 RDI: 0000000000000003
[26835.161796] RBP: 0000000000008008 R08: 000055f3d58a8010 R09: 00007f8ac3d883c0
[26835.161797] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f8ac1c22580
[26835.161798] R13: 000055f3d5894980 R14: 00000000fffffffb R15: 0000000000000003
[26835.161800] Mem-Info:
[26835.161803] active_anon:1266411 inactive_anon:922358 isolated_anon:0
                active_file:700806 inactive_file:813192 isolated_file:0
                unevictable:60 dirty:539 writeback:0 unstable:0
                slab_reclaimable:111829 slab_unreclaimable:106932
                mapped:213952 shmem:1170870 pagetables:19008 bounce:0
                free:57919 free_pcp:0 free_cma:0
[26835.161807] Node 0 active_anon:5065644kB inactive_anon:3689432kB active_file:2803224kB inactive_file:3252768kB unevictable:240kB isolated(anon):0kB isolated(file):0kB mapped:855808kB dirty:2156kB writeback:0kB shmem:4683480kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[26835.161810] DMA free:15900kB min:12kB low:24kB high:36kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15984kB managed:15900kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[26835.161811] lowmem_reserve[]: 0 1720 15616 15616
[26835.161815] DMA32 free:120040kB min:1760kB low:3520kB high:5280kB active_anon:455336kB inactive_anon:453120kB active_file:378968kB inactive_file:270764kB unevictable:0kB writepending:316kB present:1827068kB managed:1761404kB mlocked:0kB kernel_stack:320kB pagetables:2572kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[26835.161816] lowmem_reserve[]: 0 0 13896 13896
[26835.161819] Normal free:95736kB min:14220kB low:28448kB high:42676kB active_anon:4610224kB inactive_anon:3236312kB active_file:2424680kB inactive_file:2982292kB unevictable:240kB writepending:1840kB present:14655488kB managed:14351180kB mlocked:240kB kernel_stack:15440kB pagetables:73460kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[26835.161820] lowmem_reserve[]: 0 0 0 0
[26835.161822] DMA: 1*4kB (U) 1*8kB (U) 1*16kB (U) 2*32kB (U) 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15900kB
[26835.161829] DMA32: 8124*4kB (UME) 5281*8kB (UME) 2898*16kB (UME) 1*32kB (E) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 121144kB
[26835.161834] Normal: 12089*4kB (UMEH) 4927*8kB (UMEH) 549*16kB (UMEH) 3*32kB (UMH) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 96652kB
[26835.161840] 2693396 total pagecache pages
[26835.161843] 85
```63 pages in swap cache
[26835.161845] Swap cache stats: add 621731, delete 613168, find 132948/153770
[26835.161845] Free swap  = 19865684kB
[26835.161846] Total swap = 20971516kB
[26835.161847] 4124635 pages RAM
[26835.161848] 0 pages HighMem/MovableOnly
[26835.161848] 92514 pages reserved
superm1 commented 4 years ago

Can you please retry with v2.4.3? One of the WMI fixes changes the handling of the size of the requests and I think may have fixed the problem.