| Message ID | 201801112311.EHI90152.FLJMQOStVHFOFO@I-love.SAKURA.ne.jp (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Thu 11-01-18 23:11:12, Tetsuo Handa wrote: > Michal Hocko wrote: > > On Wed 10-01-18 22:37:52, Tetsuo Handa wrote: > > > Michal Hocko wrote: > > > > On Wed 10-01-18 20:49:56, Tetsuo Handa wrote: > > > > > Tetsuo Handa wrote: > > > > > > I can hit this bug with Linux 4.11 and 4.8. (i.e. at least all 4.8+ have this bug.) > > > > > > So far I haven't hit this bug with Linux 4.8-rc3 and 4.7. > > > > > > Does anyone know what is happening? > > > > > > > > > > I simplified the reproducer and succeeded to reproduce this bug with both > > > > > i7-2630QM (8 core) and i5-4440S (4 core). Thus, I think that this bug is > > > > > not architecture specific. > > > > > > > > Can you see the same with 64b kernel? > > > > > > No. I can hit this bug with only x86_32 kernels. > > > But if the cause is not specific to 32b, this might be silent memory corruption. > > > > > > > It smells like a ref count imbalance and premature page free to me. Can > > > > you try to bisect this? > > > > > > Too difficult to bisect, but at least I can hit this bug with 4.8+ kernels. > > The bug in 4.8 kernel might be different from the bug in 4.15-rc7 kernel. > 4.15-rc7 kernel hits the bug so trivially. Maybe you want to disable the oom reaper to reduce chances of some issue there.
Michal Hocko wrote: > On Thu 11-01-18 23:11:12, Tetsuo Handa wrote: > > Michal Hocko wrote: > > > On Wed 10-01-18 22:37:52, Tetsuo Handa wrote: > > > > Michal Hocko wrote: > > > > > On Wed 10-01-18 20:49:56, Tetsuo Handa wrote: > > > > > > Tetsuo Handa wrote: > > > > > > > I can hit this bug with Linux 4.11 and 4.8. (i.e. at least all 4.8+ have this bug.) > > > > > > > So far I haven't hit this bug with Linux 4.8-rc3 and 4.7. > > > > > > > Does anyone know what is happening? > > > > > > > > > > > > I simplified the reproducer and succeeded to reproduce this bug with both > > > > > > i7-2630QM (8 core) and i5-4440S (4 core). Thus, I think that this bug is > > > > > > not architecture specific. > > > > > > > > > > Can you see the same with 64b kernel? > > > > > > > > No. I can hit this bug with only x86_32 kernels. > > > > But if the cause is not specific to 32b, this might be silent memory corruption. > > > > > > > > > It smells like a ref count imbalance and premature page free to me. Can > > > > > you try to bisect this? > > > > > > > > Too difficult to bisect, but at least I can hit this bug with 4.8+ kernels. > > > > The bug in 4.8 kernel might be different from the bug in 4.15-rc7 kernel. > > 4.15-rc7 kernel hits the bug so trivially. > > Maybe you want to disable the oom reaper to reduce chances of some issue > there. I already tried it for 4.15-rc7. The bug can occur before the OOM killer is invoked for the first time after boot. The OOM killer and the OOM reaper are not the culprit.
On Thu, Jan 11, 2018 at 6:11 AM, Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp> wrote: > > I retested with some debug printk() patch. Could you perhaps enable KASAN too? > [ 38.988178] Out of memory: Kill process 354 (b.out) score 7 or sacrifice child > [ 38.991145] Killed process 354 (b.out) total-vm:2099260kB, anon-rss:23288kB, file-rss:8kB, shmem-rss:0kB > [ 38.996277] oom_reaper: started reaping > [ 38.999033] BUG: unable to handle kernel paging request at c130d86d > [ 39.001802] IP: _raw_spin_lock_irqsave+0x1c/0x40 The "Code:" line shows the whole function in this case: 0: 55 push %ebp 1: 89 c1 mov %eax,%ecx 3: 89 e5 mov %esp,%ebp 5: 56 push %esi 6: 53 push %ebx 7: 9c pushf 8: 58 pop %eax 9: 66 66 66 90 nop d: 89 c6 mov %eax,%esi f: fa cli 10: 66 66 90 nop 13: 66 90 nop 15: 31 c0 xor %eax,%eax 17: bb 01 00 00 00 mov $0x1,%ebx 1c: 3e 0f b1 19 cmpxchg %ebx,%ds:*(%ecx) <-- trapping instruction 20: 85 c0 test %eax,%eax 22: 75 06 jne 0x2a 24: 89 f0 mov %esi,%eax 26: 5b pop %ebx 27: 5e pop %esi 28: 5d pop %ebp 29: c3 ret although it isn't all that interesting since it's just "_raw_spin_lock_irqsave". The odd "nop" instructions are because of paravirtualization support leaving room for rewriting the eflags operations. Anyway, %ecx is garbage - it *should* be "&memcg->move_lock", apparently. The caller does: again: memcg = page->mem_cgroup; if (unlikely(!memcg)) return NULL; if (atomic_read(&memcg->moving_account) <= 0) return memcg; spin_lock_irqsave(&memcg->move_lock, flags); if (memcg != page->mem_cgroup) { spin_unlock_irqrestore(&memcg->move_lock, flags); goto again; } What's a bit odd is how the access to "memcg->move_lock" seems to trap, but we did that atomic_read() from memcg->moving_account ok. The reason seems to be that this is actually a valid kernel pointer, but it's read-protected: > [ 39.004069] *pde = 01f88063 *pte = 0130d161 > [ 39.006250] Oops: 0003 [#1] SMP DEBUG_PAGEALLOC That "0003" means that it was a protection fault on a write. The "*pte" thing agrees. It's the normal 1:1 mapping of the physical page 0130d000 (which matches the virtual address c130d86d), but it's presumably a kernel code pointer and this RO. So presumably "page->mem_cgroup" was just a random pointer. Which probably means that "page" itself is not actually a page pointer, sinc eI assume there was no memory hotplug going on here? > [ 39.022885] EIP: _raw_spin_lock_irqsave+0x1c/0x40 > [ 39.037889] Call Trace: > [ 39.043562] lock_page_memcg+0x25/0x80 > [ 39.045421] page_remove_rmap+0x87/0x2e0 > [ 39.047315] try_to_unmap_one+0x20e/0x590 > [ 39.049198] rmap_walk_file+0x13c/0x250 > [ 39.051012] rmap_walk+0x32/0x60 > [ 39.052619] try_to_unmap+0x4d/0x100 > [ 39.059849] shrink_page_list+0x3a2/0x1000 > [ 39.061678] shrink_inactive_list+0x1b2/0x440 > [ 39.063539] shrink_node_memcg+0x34a/0x770 > [ 39.065297] shrink_node+0xbb/0x2e0 > [ 39.066920] do_try_to_free_pages+0xba/0x320 > [ 39.068752] try_to_free_pages+0x11d/0x330 > [ 39.072084] __alloc_pages_slowpath+0x303/0x6d9 > [ 39.075932] __alloc_pages_nodemask+0x16d/0x180 > [ 39.077809] do_anonymous_page+0xab/0x4f0 > [ 39.079551] handle_mm_fault+0x531/0x8d0 > [ 39.084422] __do_page_fault+0x1ea/0x4d0 > [ 39.087666] do_page_fault+0x1a/0x20 > [ 39.089184] common_exception+0x6f/0x76 Looks like the page pointer came from shrink_inactive_list() doing isolate_lru_pages(). Scary. It all seems to just mean that the page LRU queues are corrupted. Most (all?) of your other oopses seem to have somewhat similar patterns: shrink_inactive_list() -> rmap_walk_file() -> oops due to garbage. > Overall, memory corruption is strongly suspected. Yeah, this very much looks like some internal VM memory corruption. Which is why I'm wondering if enabling KASAN might help find the actual access that causes the corruption. Or at least an _earlier_ access that is closer to it than these that all seem to be fairly far removed from where it actually all started.. Linus
Linus Torvalds wrote: > On Thu, Jan 11, 2018 at 6:11 AM, Tetsuo Handa > <penguin-kernel@i-love.sakura.ne.jp> wrote: > > > > I retested with some debug printk() patch. > > Could you perhaps enable KASAN too? Unfortunately, KASAN is not available for x86_32 kernels. Thus, I'm stuck. > So presumably "page->mem_cgroup" was just a random pointer. Which > probably means that "page" itself is not actually a page pointer, sinc > e I assume there was no memory hotplug going on here? Nothing special. No memory hotplug etc. > Most (all?) of your other oopses seem to have somewhat similar > patterns: shrink_inactive_list() -> rmap_walk_file() -> oops due to > garbage. Yes. In most cases, problems are detected by that sequence.
Tetsuo Handa wrote: > Michal Hocko wrote: > > On Wed 10-01-18 22:37:52, Tetsuo Handa wrote: > > > Michal Hocko wrote: > > > > On Wed 10-01-18 20:49:56, Tetsuo Handa wrote: > > > > > Tetsuo Handa wrote: > > > > > > I can hit this bug with Linux 4.11 and 4.8. (i.e. at least all 4.8+ have this bug.) > > > > > > So far I haven't hit this bug with Linux 4.8-rc3 and 4.7. > > > > > > Does anyone know what is happening? > > > > > > > > > > I simplified the reproducer and succeeded to reproduce this bug with both > > > > > i7-2630QM (8 core) and i5-4440S (4 core). Thus, I think that this bug is > > > > > not architecture specific. > > > > > > > > Can you see the same with 64b kernel? > > > > > > No. I can hit this bug with only x86_32 kernels. > > > But if the cause is not specific to 32b, this might be silent memory corruption. > > > > > > > It smells like a ref count imbalance and premature page free to me. Can > > > > you try to bisect this? > > > > > > Too difficult to bisect, but at least I can hit this bug with 4.8+ kernels. > > The bug in 4.8 kernel might be different from the bug in 4.15-rc7 kernel. > 4.15-rc7 kernel hits the bug so trivially. CONFIG_HIGHMEM4G=y or CONFIG_HIGHMEM64G=y x86_32 kernel hits this bug. [ 0.000000] 2184MB HIGHMEM available. [ 0.000000] 887MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 377fe000 [ 0.000000] low ram: 0 - 377fe000 [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x00000000377fdfff] [ 0.000000] HighMem [mem 0x00000000377fe000-0x00000000bfffffff] [ 0.000000] 4230MB HIGHMEM available. [ 0.000000] 889MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 379fe000 [ 0.000000] low ram: 0 - 379fe000 [ 0.000000] crashkernel: memory value expected [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x00000000379fdfff] [ 0.000000] HighMem [mem 0x00000000379fe000-0x000000013fffffff] CONFIG_NOHIGHMEM=y x86_32 kernel does not hit this bug. [ 0.000000] Warning only 891MB will be used. [ 0.000000] Use a HIGHMEM enabled kernel. [ 0.000000] 891MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 37bfe000 [ 0.000000] low ram: 0 - 37bfe000 [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x0000000037bfdfff] x86_64 kernel does not show HighMem line. [ 0.000000] Reserving 256MB of memory at 448MB for crashkernel (System RAM: 4095MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x000000013fffffff] Thus, I suspect that somewhere is confusing HighMem pages and !HighMem pages. [ 2.845150] systemd-journald[128]: Received SIGTERM from PID 1 (systemd). [ 2.859834] bash: 31 output lines suppressed due to ratelimiting [ 8.234776] random: crng init done [ 58.935340] WARNING: CPU: 0 PID: 720 at fs/xfs/xfs_aops.c:1468 xfs_vm_set_page_dirty+0x12d/0x210 [xfs] [ 58.939192] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 58.948541] CPU: 0 PID: 720 Comm: b.out Not tainted 4.15.0-rc7+ #309 [ 58.951330] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 58.956375] EIP: xfs_vm_set_page_dirty+0x12d/0x210 [xfs] [ 58.958909] EFLAGS: 00010046 CPU: 0 [ 58.960846] EAX: 13000010 EBX: f3bd61d8 ECX: f3bd61d8 EDX: f3bd61cc [ 58.963663] ESI: 00000246 EDI: f4503f68 EBP: eed8d9ec ESP: eed8d9c4 [ 58.966515] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 58.969065] CR0: 80050033 CR2: b7f07700 CR3: 33453a80 CR4: 000406f0 [ 58.971948] Call Trace: [ 58.973593] set_page_dirty+0x42/0xa0 [ 58.975606] try_to_unmap_one+0x417/0x6c0 [ 58.977768] rmap_walk_file+0xf0/0x1e0 [ 58.979878] rmap_walk+0x37/0x60 [ 58.981781] try_to_unmap+0x52/0xd0 [ 58.983645] ? page_remove_rmap+0x270/0x270 [ 58.985938] ? page_not_mapped+0x20/0x20 [ 58.988044] ? page_get_anon_vma+0x80/0x80 [ 58.990222] shrink_page_list+0x3f6/0xef0 [ 58.992275] shrink_inactive_list+0x1c2/0x530 [ 58.994528] ? check_preempt_wakeup+0x181/0x230 [ 58.996757] shrink_node_memcg+0x352/0x770 [ 58.998710] shrink_node+0xc3/0x2f0 [ 59.000481] do_try_to_free_pages+0xc9/0x320 [ 59.002494] try_to_free_pages+0x163/0x420 [ 59.004472] __alloc_pages_slowpath+0x280/0x8e4 [ 59.006613] ? release_pages+0x13a/0x340 [ 59.008508] ? __accumulate_pelt_segments+0x37/0x50 [ 59.010835] __alloc_pages_nodemask+0x23b/0x260 [ 59.012955] do_anonymous_page+0xef/0x5a0 [ 59.014879] ? set_next_entity+0x96/0x280 [ 59.016772] handle_mm_fault+0x888/0xa50 [ 59.018665] __do_page_fault+0x1e3/0x4d0 [ 59.020609] ? __do_page_fault+0x4d0/0x4d0 [ 59.022481] do_page_fault+0x29/0xe0 [ 59.024165] ? __do_page_fault+0x4d0/0x4d0 [ 59.025992] ? __do_page_fault+0x4d0/0x4d0 [ 59.027808] common_exception+0x6f/0x76 [ 59.029566] EIP: 0x8048437 [ 59.031034] EFLAGS: 00010202 CPU: 0 [ 59.032699] EAX: 004c5000 EBX: 7ff00000 ECX: 382cd008 EDX: 00000000 [ 59.035109] ESI: 7ff00000 EDI: 00000000 EBP: bfbc6198 ESP: bfbc6160 [ 59.037516] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b [ 59.039825] Code: e4 8d 58 0c 89 d8 e8 23 c6 8c c8 89 c6 8b 45 e8 8b 50 04 85 d2 74 5b 8b 40 14 a8 01 0f 85 d3 00 00 00 8b 45 e8 8b 00 a8 08 75 7b <0f> ff 8b 7d e8 8b 55 e4 89 f8 e8 94 0a 38 c8 8b 47 14 a8 01 0f [ 59.046971] ---[ end trace a3882c406e0b0b93 ]--- [ 59.061588] b.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0 [ 59.066371] b.out cpuset=/ mems_allowed=0 [ 59.068273] CPU: 0 PID: 798 Comm: b.out Tainted: G W 4.15.0-rc7+ #309 [ 59.071107] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 59.075456] Call Trace: [ 59.076963] dump_stack+0x58/0x78 [ 59.078653] dump_header+0x70/0x271 [ 59.080371] ? ___ratelimit+0x83/0xf0 [ 59.082086] oom_kill_process+0x1f5/0x3f0 [ 59.083881] ? has_capability_noaudit+0x1a/0x30 [ 59.086106] ? oom_badness+0xe1/0x140 [ 59.087885] out_of_memory+0xe6/0x280 [ 59.089653] __alloc_pages_slowpath+0x647/0x8e4 [ 59.091643] __alloc_pages_nodemask+0x23b/0x260 [ 59.093741] do_anonymous_page+0xef/0x5a0 [ 59.095767] ? set_next_entity+0x96/0x280 [ 59.097770] handle_mm_fault+0x888/0xa50 [ 59.099640] __do_page_fault+0x1e3/0x4d0 [ 59.101440] ? __do_page_fault+0x4d0/0x4d0 [ 59.103344] do_page_fault+0x29/0xe0 [ 59.105011] ? __do_page_fault+0x4d0/0x4d0 [ 59.106821] ? __do_page_fault+0x4d0/0x4d0 [ 59.108635] common_exception+0x6f/0x76 [ 59.110432] EIP: 0x8048437 [ 59.111920] EFLAGS: 00010202 CPU: 0 [ 59.113598] EAX: 003e5000 EBX: 7ff00000 ECX: 382a3008 EDX: 00000000 [ 59.116181] ESI: 7ff00000 EDI: 00000000 EBP: bf8ccc08 ESP: bf8ccbd0 [ 59.118630] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b [ 59.120851] ? move_vma+0x90/0x280 [ 59.122535] Mem-Info: [ 59.123848] active_anon:957369 inactive_anon:2048 isolated_anon:0 [ 59.123848] active_file:8 inactive_file:32 isolated_file:34 [ 59.123848] unevictable:0 dirty:0 writeback:0 unstable:0 [ 59.123848] slab_reclaimable:1481 slab_unreclaimable:2749 [ 59.123848] mapped:0 shmem:2050 pagetables:24289 bounce:0 [ 59.123848] free:39933 free_pcp:63 free_cma:0 [ 59.137797] Node 0 active_anon:3829476kB inactive_anon:8192kB active_file:32kB inactive_file:128kB unevictable:0kB isolated(anon):0kB isolated(file):136kB mapped:0kB dirty:0kB writeback:0kB shmem:8200kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? yes [ 59.150272] DMA free:15912kB min:788kB low:984kB high:1180kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 59.164549] lowmem_reserve[]: 0 803 4009 4009 [ 59.166791] Normal free:143380kB min:40868kB low:51084kB high:61300kB active_anon:568644kB inactive_anon:0kB active_file:20kB inactive_file:44kB unevictable:0kB writepending:0kB present:894968kB managed:840896kB mlocked:0kB kernel_stack:4760kB pagetables:97156kB bounce:0kB free_pcp:120kB local_pcp:120kB free_cma:0kB [ 59.179026] lowmem_reserve[]: 0 0 25647 25647 [ 59.181335] HighMem free:440kB min:512kB low:41276kB high:82040kB active_anon:3260828kB inactive_anon:8192kB active_file:12kB inactive_file:24kB unevictable:0kB writepending:0kB present:3282888kB managed:3282888kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:132kB local_pcp:132kB free_cma:0kB [ 59.193942] lowmem_reserve[]: 0 0 0 0 [ 59.196116] DMA: 0*4kB 1*8kB (U) 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15912kB [ 59.202192] Normal: 159*4kB (UE) 91*8kB (UE) 36*16kB (UME) 18*32kB (UE) 9*64kB (UE) 6*128kB (UME) 3*256kB (UE) 3*512kB (UME) 2*1024kB (ME) 2*2048kB (UE) 32*4096kB (M) = 143380kB [ 59.209381] HighMem: 6*4kB (UM) 4*8kB (UM) 4*16kB (UM) 4*32kB (UM) 1*64kB (M) 1*128kB (U) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 440kB [ 59.215678] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB [ 59.220196] 2125 total pagecache pages [ 59.222587] 0 pages in swap cache [ 59.224777] Swap cache stats: add 0, delete 0, find 0/0 [ 59.227634] Free swap = 0kB [ 59.229594] Total swap = 0kB [ 59.231533] 1048462 pages RAM [ 59.233527] 820722 pages HighMem/MovableOnly [ 59.235870] 13537 pages reserved [ 59.237905] 0 pages cma reserved [ 59.239980] Out of memory: Kill process 388 (b.out) score 3 or sacrifice child [ 59.243277] Killed process 388 (b.out) total-vm:2099260kB, anon-rss:16688kB, file-rss:12kB, shmem-rss:0kB [ 66.736837] ------------[ cut here ]------------ [ 66.739227] list_add corruption. next->prev should be prev (cf64836e), but was 6673909a. (next=b675dd8b). [ 66.743934] WARNING: CPU: 0 PID: 720 at lib/list_debug.c:25 __list_add_valid+0x3f/0x90 [ 66.747137] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 66.756725] CPU: 0 PID: 720 Comm: b.out Tainted: G W 4.15.0-rc7+ #309 [ 66.759984] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 66.764940] EIP: __list_add_valid+0x3f/0x90 [ 66.767046] EFLAGS: 00010096 CPU: 0 [ 66.768984] EAX: 0000005d EBX: 00000200 ECX: c1b3bce8 EDX: 00000086 [ 66.771626] ESI: f4503f7c EDI: f4503f7c EBP: eed8db40 ESP: eed8db2c [ 66.774286] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 66.776701] CR0: 80050033 CR2: 08048437 CR3: 33453a80 CR4: 000406f0 [ 66.779404] Call Trace: [ 66.781033] putback_inactive_pages+0x13f/0x3b0 [ 66.783198] shrink_inactive_list+0x215/0x530 [ 66.785300] ? check_preempt_wakeup+0x181/0x230 [ 66.787465] shrink_node_memcg+0x352/0x770 [ 66.789431] shrink_node+0xc3/0x2f0 [ 66.791192] do_try_to_free_pages+0xc9/0x320 [ 66.793156] try_to_free_pages+0x163/0x420 [ 66.795057] __alloc_pages_slowpath+0x280/0x8e4 [ 66.797072] ? release_pages+0x13a/0x340 [ 66.798908] ? __accumulate_pelt_segments+0x37/0x50 [ 66.800993] __alloc_pages_nodemask+0x23b/0x260 [ 66.802991] do_anonymous_page+0xef/0x5a0 [ 66.804855] ? set_next_entity+0x96/0x280 [ 66.806716] handle_mm_fault+0x888/0xa50 [ 66.808573] __do_page_fault+0x1e3/0x4d0 [ 66.810423] ? __do_page_fault+0x4d0/0x4d0 [ 66.812325] do_page_fault+0x29/0xe0 [ 66.814069] ? __do_page_fault+0x4d0/0x4d0 [ 66.815902] ? __do_page_fault+0x4d0/0x4d0 [ 66.817738] common_exception+0x6f/0x76 [ 66.819512] EIP: 0x8048437 [ 66.820931] EFLAGS: 00010202 CPU: 0 [ 66.822529] EAX: 004c5000 EBX: 7ff00000 ECX: 382cd008 EDX: 00000000 [ 66.824891] ESI: 7ff00000 EDI: 00000000 EBP: bfbc6198 ESP: bfbc6160 [ 66.827199] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b [ 66.829285] Code: 39 c8 74 2d 39 c3 74 29 b8 01 00 00 00 83 c4 10 5b 5d c3 89 4c 24 0c 89 5c 24 08 89 54 24 04 c7 04 24 70 aa 8d c1 e8 b1 e5 d2 ff <0f> ff 31 c0 eb dc 89 4c 24 0c 89 5c 24 08 89 44 24 04 c7 04 24 [ 66.836182] ---[ end trace a3882c406e0b0b94 ]--- [ 66.844058] ------------[ cut here ]------------ [ 66.845963] list_add corruption. next->prev should be prev (cf64836e), but was 6673909a. (next=b675dd8b). [ 66.849814] WARNING: CPU: 0 PID: 30 at lib/list_debug.c:25 __list_add_valid+0x3f/0x90 [ 66.852599] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 66.861186] CPU: 0 PID: 30 Comm: kswapd0 Tainted: G W 4.15.0-rc7+ #309 [ 66.864078] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 66.868375] EIP: __list_add_valid+0x3f/0x90 [ 66.870277] EFLAGS: 00010096 CPU: 0 [ 66.872003] EAX: 0000005d EBX: 00000200 ECX: c1b3bce8 EDX: 00000082 [ 66.874461] ESI: f4503f7c EDI: f55738bc EBP: f352dd50 ESP: f352dd3c [ 66.876985] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 66.879233] CR0: 80050033 CR2: b7d9f2a0 CR3: 33560d20 CR4: 000406f0 [ 66.881768] Call Trace: [ 66.883233] putback_inactive_pages+0x13f/0x3b0 [ 66.885256] shrink_inactive_list+0x215/0x530 [ 66.887211] shrink_node_memcg+0x352/0x770 [ 66.889120] ? _cond_resched+0x17/0x30 [ 66.890928] shrink_node+0xc3/0x2f0 [ 66.892748] kswapd+0x257/0x670 [ 66.894395] kthread+0xdb/0x110 [ 66.896078] ? mem_cgroup_shrink_node+0x160/0x160 [ 66.898157] ? kthread_worker_fn+0x160/0x160 [ 66.900153] ret_from_fork+0x19/0x24 [ 66.901902] Code: 39 c8 74 2d 39 c3 74 29 b8 01 00 00 00 83 c4 10 5b 5d c3 89 4c 24 0c 89 5c 24 08 89 54 24 04 c7 04 24 70 aa 8d c1 e8 b1 e5 d2 ff <0f> ff 31 c0 eb dc 89 4c 24 0c 89 5c 24 08 89 44 24 04 c7 04 24 [ 66.909496] ---[ end trace a3882c406e0b0b95 ]--- (...snipped...) [ 67.964739] ------------[ cut here ]------------ [ 67.966833] list_add corruption. next->prev should be prev (cf64836e), but was 6673909a. (next=b675dd8b). [ 67.971133] WARNING: CPU: 0 PID: 30 at lib/list_debug.c:25 __list_add_valid+0x3f/0x90 [ 67.974100] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 67.982900] CPU: 0 PID: 30 Comm: kswapd0 Tainted: G W 4.15.0-rc7+ #309 [ 67.985849] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 67.990519] EIP: __list_add_valid+0x3f/0x90 [ 67.992533] EFLAGS: 00010096 CPU: 0 [ 67.994334] EAX: 0000005d EBX: 00000200 ECX: c1b3bce8 EDX: 00000082 [ 67.996837] ESI: f4503f7c EDI: f5573b14 EBP: f352dd50 ESP: f352dd3c [ 67.999430] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 68.001757] CR0: 80050033 CR2: b7d9f2a0 CR3: 33436e20 CR4: 000406f0 [ 68.004304] Call Trace: [ 68.005785] putback_inactive_pages+0x13f/0x3b0 [ 68.007812] shrink_inactive_list+0x215/0x530 [ 68.009804] shrink_node_memcg+0x352/0x770 [ 68.011771] ? _cond_resched+0x17/0x30 [ 68.013593] shrink_node+0xc3/0x2f0 [ 68.015379] kswapd+0x257/0x670 [ 68.017047] kthread+0xdb/0x110 [ 68.018674] ? mem_cgroup_shrink_node+0x160/0x160 [ 68.020700] ? kthread_worker_fn+0x160/0x160 [ 68.022667] ret_from_fork+0x19/0x24 [ 68.024436] Code: 39 c8 74 2d 39 c3 74 29 b8 01 00 00 00 83 c4 10 5b 5d c3 89 4c 24 0c 89 5c 24 08 89 54 24 04 c7 04 24 70 aa 8d c1 e8 b1 e5 d2 ff <0f> ff 31 c0 eb dc 89 4c 24 0c 89 5c 24 08 89 44 24 04 c7 04 24 [ 68.031947] ---[ end trace a3882c406e0b0ba3 ]--- [ 68.034203] ------------[ cut here ]------------ [ 68.036504] list_del corruption, b675dd8b->next is LIST_POISON1 (490f1932) [ 68.039405] WARNING: CPU: 0 PID: 30 at lib/list_debug.c:47 __list_del_entry_valid+0x47/0xa0 [ 68.042497] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 68.051350] CPU: 0 PID: 30 Comm: kswapd0 Tainted: G W 4.15.0-rc7+ #309 [ 68.054343] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 68.059006] EIP: __list_del_entry_valid+0x47/0xa0 [ 68.061197] EFLAGS: 00010086 CPU: 0 [ 68.063002] EAX: 0000003e EBX: f4503f7c ECX: c1b3bce8 EDX: 00000082 [ 68.065590] ESI: f3c60c18 EDI: f352dd90 EBP: f352dd4c ESP: f352dd40 [ 68.068098] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 68.070375] CR0: 80050033 CR2: b7d9f2a0 CR3: 33436e20 CR4: 000406f0 [ 68.072858] Call Trace: [ 68.074311] isolate_lru_pages.isra.65+0x210/0x360 [ 68.076482] ? putback_inactive_pages+0x13f/0x3b0 [ 68.078583] ? apic_timer_interrupt+0x3c/0x44 [ 68.080537] shrink_active_list+0xb1/0x3a0 [ 68.082502] ? inactive_list_is_low.isra.64+0x12b/0x1f0 [ 68.084688] shrink_node_memcg+0x3a2/0x770 [ 68.086600] shrink_node+0xc3/0x2f0 [ 68.088372] kswapd+0x257/0x670 [ 68.090007] kthread+0xdb/0x110 [ 68.091642] ? mem_cgroup_shrink_node+0x160/0x160 [ 68.093779] ? kthread_worker_fn+0x160/0x160 [ 68.095686] ret_from_fork+0x19/0x24 [ 68.097479] Code: 09 39 c8 75 46 8b 52 04 39 d0 75 25 b8 01 00 00 00 c9 c3 89 44 24 04 c7 44 24 08 00 01 00 00 c7 04 24 40 ab 8d c1 e8 19 e5 d2 ff <0f> ff 31 c0 c9 c3 89 54 24 08 89 44 24 04 c7 04 24 e4 ab 8d c1 [ 68.104937] ---[ end trace a3882c406e0b0ba4 ]--- [ 68.107030] ------------[ cut here ]------------ [ 68.109187] kernel BUG at mm/vmscan.c:1560! [ 68.111147] invalid opcode: 0000 [#1] SMP [ 68.112978] Modules linked in: xfs libcrc32c sr_mod cdrom ata_generic sd_mod pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mptspi drm crc32c_intel scsi_transport_spi serio_raw ata_piix mptscsih libata e1000 mptbase i2c_core [ 68.121527] CPU: 0 PID: 30 Comm: kswapd0 Tainted: G W 4.15.0-rc7+ #309 [ 68.124410] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 68.129258] EIP: isolate_lru_pages.isra.65+0x248/0x360 [ 68.132206] EFLAGS: 00010082 CPU: 0 [ 68.134103] EAX: ffffffea EBX: f4503f7c ECX: f352df68 EDX: 00000000 [ 68.136776] ESI: f3c60c18 EDI: 00000001 EBP: f352ddc8 ESP: f352dd54 [ 68.139404] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 68.141700] CR0: 80050033 CR2: b7d9f2a0 CR3: 33436e20 CR4: 000406f0 [ 68.144202] Call Trace: [ 68.145656] ? putback_inactive_pages+0x13f/0x3b0 [ 68.147714] ? apic_timer_interrupt+0x3c/0x44 [ 68.149628] shrink_active_list+0xb1/0x3a0 [ 68.151576] ? inactive_list_is_low.isra.64+0x12b/0x1f0 [ 68.153749] shrink_node_memcg+0x3a2/0x770 [ 68.155605] shrink_node+0xc3/0x2f0 [ 68.157303] kswapd+0x257/0x670 [ 68.158884] kthread+0xdb/0x110 [ 68.160500] ? mem_cgroup_shrink_node+0x160/0x160 [ 68.162491] ? kthread_worker_fn+0x160/0x160 [ 68.164366] ret_from_fork+0x19/0x24 [ 68.166050] Code: 10 8b 45 b0 8b 38 89 c2 89 d8 89 f9 e8 02 36 1b 00 84 c0 0f 84 d5 fe ff ff 8b 45 b0 89 5f 04 89 3b 89 43 04 89 18 e9 c3 fe ff ff <0f> 0b 8d b6 00 00 00 00 89 d8 e8 69 36 1b 00 84 c0 74 0a 8b 13 [ 68.173408] EIP: isolate_lru_pages.isra.65+0x248/0x360 SS:ESP: 0068:f352dd54 [ 68.176105] ---[ end trace a3882c406e0b0ba5 ]--- [ 68.178248] Kernel panic - not syncing: Fatal exception [ 68.180517] Kernel Offset: 0x0 from 0xc1000000 (relocation range: 0xc0000000-0xf81fdfff) [ 68.183605] Rebooting in 5 seconds.. [ 73.262601] ACPI MEMORY or I/O RESET_REG.
On Thu, Jan 11, 2018 at 5:31 PM, Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp> wrote: > > Thus, I suspect that somewhere is confusing HighMem pages and !HighMem pages. Hmm. I can't even imagine how you'd do that. Sure, if you take page_address() to get a kmap'ed linear address, and then feed that linear address back to virt_to_page(), you'd certainly get a crazy page. But that would be insane.. I don't see how you'd do that. Hmm. Do you have CONFIG_DEBUG_VIRTUAL enabled? That should catch at least the above case, it should enable a debugging version of __virt_to_phys() and use it. Linus
Tetsuo Handa wrote: > Michal Hocko wrote: > > All of those seem to be file pages. So maybe try to use a different FS. > > Maybe that's the next thing I should try. xfs versus ext4 => Both triggers the bug Linus Torvalds wrote: > On Thu, Jan 11, 2018 at 5:31 PM, Tetsuo Handa > <penguin-kernel@i-love.sakura.ne.jp> wrote: > > > > Thus, I suspect that somewhere is confusing HighMem pages and !HighMem pages. > > Hmm. I can't even imagine how you'd do that. > > Sure, if you take page_address() to get a kmap'ed linear address, and > then feed that linear address back to virt_to_page(), you'd certainly > get a crazy page. But that would be insane.. I don't see how you'd do > that. > > Hmm. Do you have CONFIG_DEBUG_VIRTUAL enabled? That should catch at > least the above case, it should enable a debugging version of > __virt_to_phys() and use it. > CONFIG_DEBUG_VIRTUAL=y versus CONFIG_DEBUG_VIRTUAL=n => No difference No mem= parameter versus mem=768M => Cannot trigger if mem=768M (i.e. not using HighMem) CONFIG_SLUB=y versus CONFIG_SLAB=y => Both triggers the bug CONFIG_DEBUG_PAGEALLOC=y versus CONFIG_DEBUG_PAGEALLOC=n => Cannot trigger if CONFIG_DEBUG_PAGEALLOC=n I don't know whether there is a bug in CONFIG_DEBUG_PAGEALLOC=y code. Config is at http://I-love.SAKURA.ne.jp/tmp/config-4.15-rc7-min .
This memory corruption bug occurs even on CONFIG_SMP=n CONFIG_PREEMPT_NONE=y
kernel. This bug highly depends on timing and thus too difficult to bisect.
This bug seems to exist at least since Linux 4.8 (judging from the traces, though
the cause might be different). None of debugging configuration gives me a clue.
So far only CONFIG_HIGHMEM=y CONFIG_DEBUG_PAGEALLOC=y kernel (with RAM enough to
use HighMem: zone) seems to hit this bug, but it might be just by chance caused
by timings. Thus, there is no evidence that 64bit kernels are not affected by
this bug. But I can't narrow down any more. Thus, I call for developers who can
narrow down / identify where the memory corruption bug is.
Depends on block device?
Can't reproduce if executing reproducer from initramfs.
But maybe this is due to timing dependent.
Depends on dynamic link?
Can't reproduce if reproducer is statically linked.
But maybe this is due to timing dependent.
Depends on hypervisor?
Can reproduce on both VMware and QEMU.
Depends on filesystem?
Can reproduce on xfs, ext4 and cramfs.
Below is complete procedure for reproducing this bug using minimal kernel
config tuned for QEMU running on x86_64 CentOS 7.4 host.
(1) Create a disk image with minimal contents.
qemu-img create -f raw /mnt/disk1.img 128M
mkfs.xfs /mnt/disk1.img
mount -o loop /mnt/disk1.img /mnt/
gcc -Wall -O3 -m32 -o /mnt/init -x c - << "EOF"
#include <unistd.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <sys/mount.h>
#include <sys/wait.h>
int main(int argc, char *argv[])
{
int fd;
mount("/proc", "/proc", "proc", 0, NULL);
fd = open("/proc/sys/vm/oom_dump_tasks", O_WRONLY);
write(fd, "0\n", 2);
close(fd);
while (1) {
write(1, "Starting a.out\n", 15);
if (fork() == 0) {
execlp("/a.out", "/a.out", NULL);
write(1, "Failed\n", 7);
_exit(0);
}
wait(NULL);
}
return 0;
}
EOF
gcc -Wall -O3 -m32 -o /mnt/a.out -x c - << "EOF"
#include <stdlib.h>
#include <unistd.h>
int main(int argc, char *argv[])
{
if (argc != 1) {
unsigned long long size;
char *buf = NULL;
unsigned long long i;
for (size = 1048576; size < 512ULL * (1 << 30); size += 1048576) {
char *cp = realloc(buf, size);
if (!cp) {
size -= 1048576;
break;
}
buf = cp;
}
for (i = 0; i < size; i += 4096)
buf[i] = 0;
_exit(0);
} else
while (1)
if (fork() == 0)
execlp(argv[0], argv[0], "", NULL);
return 0;
}
EOF
mkdir /mnt/lib /mnt/proc /mnt/dev
cp -pL /lib/libc.so.6 /lib/ld-linux.so.2 /mnt/lib/
umount -d /mnt/
(2) Build a 32bit kernel and boot it with the disk image.
cd /path/to/linux.git
wget -O .config http://I-love.SAKURA.ne.jp/tmp/config-4.15-rc7-min-qemu
make -s
/usr/libexec/qemu-kvm -no-kvm -machine pc -cpu kvm32 -smp 1 -m 2048 --no-reboot --kernel arch/x86/boot/bzImage --nographic --append "ro console=ttyS0,115200n8 root=/dev/vda init=/init" -drive file=/mnt/disk1.img,if=virtio
An example result is shown below.
[ 0.000000] Linux version 4.15.0-rc7+ (root@ccsecurity) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC)) #220 Sun Jan 14 20:36:37 JST 2018
[ 0.000000] x86/fpu: x87 FPU will use FXSAVE
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffbfff] usable
[ 0.000000] BIOS-e820: [mem 0x000000007fffc000-0x000000007fffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[ 0.000000] Notice: NX (Execute Disable) protection missing in CPU!
[ 0.000000] random: fast init done
[ 0.000000] SMBIOS 2.4 present.
[ 0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 0.000000] e820: last_pfn = 0x7fffc max_arch_pfn = 0x100000
[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- UC
[ 0.000000] found SMP MP-table at [mem 0x000f7300-0x000f730f] mapped at [(ptrval)]
[ 0.000000] Scanning 1 areas for low memory corruption
[ 0.000000] ACPI: Early table checksum verification disabled
[ 0.000000] ACPI: RSDP 0x00000000000F7160 000014 (v00 BOCHS )
[ 0.000000] ACPI: RSDT 0x000000007FFFFA9B 000030 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACP 0x000000007FFFF177 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
[ 0.000000] ACPI: DSDT 0x000000007FFFE040 001137 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACS 0x000000007FFFE000 000040
[ 0.000000] ACPI: SSDT 0x000000007FFFF1EB 000838 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: APIC 0x000000007FFFFA23 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[ 0.000000] 1159MB HIGHMEM available.
[ 0.000000] 887MB LOWMEM available.
[ 0.000000] mapped low ram: 0 - 377fe000
[ 0.000000] low ram: 0 - 377fe000
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]
[ 0.000000] Normal [mem 0x0000000001000000-0x00000000377fdfff]
[ 0.000000] HighMem [mem 0x00000000377fe000-0x000000007fffbfff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]
[ 0.000000] node 0: [mem 0x0000000000100000-0x000000007fffbfff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffbfff]
[ 0.000000] Reserved but unavailable: 98 pages
[ 0.000000] Using APIC driver default
[ 0.000000] ACPI: PM-Timer IO Port: 0x608
[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.000000] IOAPIC[0]: apic_id 0 already used, trying 1
[ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.000000] Using ACPI (MADT) for SMP configuration information
[ 0.000000] e820: [mem 0x80000000-0xfffbffff] available for PCI devices
[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 521966
[ 0.000000] Kernel command line: ro console=ttyS0,115200n8 root=/dev/vda init=/init
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Initializing CPU#0
[ 0.000000] Initializing HighMem for node 0 (000377fe:0007fffc)
[ 0.000000] Initializing Movable for node 0 (00000000:00000000)
[ 0.000000] Memory: 2064228K/2096744K available (3330K kernel code, 256K rwdata, 916K rodata, 380K init, 5308K bss, 32516K reserved, 0K cma-reserved, 1187832K highmem)
[ 0.000000] virtual kernel memory layout:
[ 0.000000] fixmap : 0xfffa4000 - 0xfffff000 ( 364 kB)
[ 0.000000] cpu_entry : 0xffc00000 - 0xffc28000 ( 160 kB)
[ 0.000000] pkmap : 0xff800000 - 0xffc00000 (4096 kB)
[ 0.000000] vmalloc : 0xf7ffe000 - 0xff7fe000 ( 120 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xf77fe000 ( 887 MB)
[ 0.000000] .init : 0xc1474000 - 0xc14d3000 ( 380 kB)
[ 0.000000] .data : 0xc1340b0a - 0xc14693a0 (1186 kB)
[ 0.000000] .text : 0xc1000000 - 0xc1340b0a (3330 kB)
[ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] NR_IRQS: 2304, nr_irqs: 256, preallocated irqs: 16
[ 0.000000] Console: colour VGA+ 80x25
[ 0.000000] console [ttyS0] enabled
[ 0.000000] ACPI: Core revision 20170831
[ 0.000000] ACPI: 2 ACPI AML tables successfully acquired and loaded
[ 0.002000] APIC: Switch to symmetric I/O mode setup
[ 0.002000] Enabling APIC mode: Flat. Using 1 I/O APICs
[ 0.003000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.008000] tsc: Fast TSC calibration using PIT
[ 0.009000] tsc: Detected 2793.513 MHz processor
[ 0.010000] Calibrating delay loop (skipped), value calculated using timer frequency.. 5587.02 BogoMIPS (lpj=2793513)
[ 0.010000] pid_max: default: 32768 minimum: 301
[ 0.011243] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.011590] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.019489] mce: CPU supports 10 MCE banks
[ 0.020000] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.020000] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.020000] CPU: Intel Common 32-bit KVM processor (family: 0xf, model: 0x6, stepping: 0x1)
[ 0.029000] Performance Events: unsupported Netburst CPU model 6 no PMU driver, software events only.
[ 0.032000] APIC calibration not consistent with PM-Timer: 193ms instead of 100ms
[ 0.032000] APIC delta adjusted to PM-Timer: 6250001 (12069151)
[ 0.035000] devtmpfs: initialized
[ 0.037160] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[ 0.037567] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.042266] cpuidle: using governor menu
[ 0.043000] ACPI: bus type PCI registered
[ 0.044933] PCI: PCI BIOS revision 2.10 entry at 0xfd54b, last bus=0
[ 0.045000] PCI: Using configuration type 1 for base access
[ 0.051898] HugeTLB registered 4.00 MiB page size, pre-allocated 0 pages
[ 0.054220] ACPI: Added _OSI(Module Device)
[ 0.054416] ACPI: Added _OSI(Processor Device)
[ 0.054553] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 0.054696] ACPI: Added _OSI(Processor Aggregator Device)
[ 0.071000] ACPI: Interpreter enabled
[ 0.071000] ACPI: (supports S0 S5)
[ 0.071000] ACPI: Using IOAPIC for interrupt routing
[ 0.071516] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 0.073000] ACPI: Enabled 16 GPEs in block 00 to 0F
[ 0.094000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 0.094000] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[ 0.094128] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[ 0.095318] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[ 0.099000] PCI host bridge to bus 0000:00
[ 0.099211] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
[ 0.099484] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
[ 0.099616] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[ 0.099731] pci_bus 0000:00: root bus resource [mem 0x80000000-0xfebfffff window]
[ 0.099926] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.106000] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
[ 0.106078] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
[ 0.106325] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
[ 0.106486] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
[ 0.108636] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
[ 0.108866] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
[ 0.127454] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[ 0.128000] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[ 0.128508] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[ 0.129000] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[ 0.129574] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[ 0.134000] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[ 0.134000] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[ 0.134068] pci 0000:00:02.0: vgaarb: bridge control possible
[ 0.134233] vgaarb: loaded
[ 0.135514] SCSI subsystem initialized
[ 0.136526] PCI: Using ACPI for IRQ routing
[ 0.137000] clocksource: Switched to clocksource refined-jiffies
[ 0.138266] ACPI: Failed to create genetlink family for ACPI event
[ 0.139337] pnp: PnP ACPI init
[ 0.144998] pnp: PnP ACPI: found 5 devices
[ 0.172994] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 0.173217] clocksource: Switched to clocksource acpi_pm
[ 0.173994] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 0.173994] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 0.173994] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 0.173994] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[ 0.183369] Scanning for low memory corruption every 60 seconds
[ 0.189392] workingset: timestamp_bits=14 max_order=19 bucket_order=5
[ 0.204712] zbud: loaded
[ 0.210911] SGI XFS with ACLs, security attributes, no debug enabled
[ 0.220200] bounce: pool size: 64 pages
[ 0.220200] io scheduler noop registered (default)
[ 0.229848] atomic64_test: passed for i586+ platform with CX8 and with SSE
[ 0.236151] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 0.237081] ACPI: Power Button [PWRF]
[ 0.248193] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 0.248193] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[ 0.254507] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 0.277797] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 0.293374] Non-volatile memory driver v1.3
[ 0.337929] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 0.342766] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 0.344004] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 0.347349] Using IPI Shortcut mode
[ 0.347732] sched_clock: Marking stable (347235515, 0)->(709645618, -362410103)
[ 0.350608] page_owner is disabled
[ 0.375161] XFS (vda): Mounting V5 Filesystem
[ 0.434199] XFS (vda): Ending clean mount
[ 0.466036] VFS: Mounted root (xfs filesystem) readonly on device 254:0.
[ 0.468423] devtmpfs: mounted
[ 0.469817] debug: unmapping init [mem 0xc1474000-0xc14d2fff]
[ 0.471908] Write protecting the kernel text: 3332k
[ 0.472225] Write protecting the kernel read-only data: 928k
Starting a.out
[ 1.184498] tsc: Refined TSC clocksource calibration: 2793.541 MHz
[ 1.184788] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x28446b3c7b0, max_idle_ns: 440795331399 ns
[ 2.262012] clocksource: Switched to clocksource tsc
/a.out: error while loading shared libraries: cannot create cache for search path: Cannot allocate memory
/a.out: error while loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate memory
/a.out: error while loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate memory
cannot allocate TLS data structures for initial thread/a.out: error while loading shared libraries: cannot create cache for search path: Cannot allocate memory
/a.out: error while loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate memory
/a.out: error while loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate memory
/a.out: error while loading shared libraries: libc.so.6: failed to map segment from shared object: Cannot allocate memory
[ 40.328889] a.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[ 40.329204] CPU: 0 PID: 144 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 40.329371] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 40.329676] Call Trace:
[ 40.330675] dump_stack+0x16/0x24
[ 40.330901] dump_header+0x64/0x211
[ 40.330991] ? irq_exit+0x2a/0x90
[ 40.331052] ? smp_apic_timer_interrupt+0x45/0x80
[ 40.331122] oom_kill_process+0x1ec/0x400
[ 40.331183] ? has_capability_noaudit+0x1f/0x30
[ 40.331248] ? oom_badness+0xc6/0x140
[ 40.331365] ? oom_evaluate_task+0xa2/0xe0
[ 40.331561] out_of_memory+0xe0/0x270
[ 40.331625] __alloc_pages_nodemask+0x6a3/0x830
[ 40.331697] handle_mm_fault+0xa5e/0xdd0
[ 40.331768] ? slow_virt_to_phys+0x2b/0x90
[ 40.331886] __do_page_fault+0x194/0x420
[ 40.331969] ? vmalloc_sync_all+0x150/0x150
[ 40.332040] do_page_fault+0xb/0xd
[ 40.332093] common_exception+0x6d/0x72
[ 40.332599] EIP: 0x8048437
[ 40.332948] EFLAGS: 00000202 CPU: 0
[ 40.333046] EAX: 007a3000 EBX: 7ff00000 ECX: 3862e008 EDX: 00000000
[ 40.333479] ESI: 7ff00000 EDI: 00000000 EBP: bfd4b908 ESP: bfd4b8d0
[ 40.333643] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 40.333995] Mem-Info:
[ 40.334767] active_anon:483450 inactive_anon:0 isolated_anon:0
[ 40.334767] active_file:0 inactive_file:10 isolated_file:55
[ 40.334767] unevictable:0 dirty:0 writeback:0 unstable:0
[ 40.334767] slab_reclaimable:26 slab_unreclaimable:919
[ 40.334767] mapped:40 shmem:0 pagetables:8018 bounce:0
[ 40.334767] free:22250 free_pcp:190 free_cma:0
[ 40.335681] Node 0 active_anon:1933800kB inactive_anon:0kB active_file:0kB inactive_file:40kB unevictable:0kB isolated(anon):0kB isolated(file):220kB mapped:160kB dirty:0kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 40.336482] DMA free:8788kB min:788kB low:984kB high:1180kB active_anon:7128kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 40.336893] lowmem_reserve[]: 0 840 2000 2000
[ 40.337028] Normal free:79804kB min:42744kB low:53428kB high:64112kB active_anon:739736kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:892920kB managed:860480kB mlocked:0kB kernel_stack:2400kB pagetables:32072kB bounce:0kB free_pcp:640kB local_pcp:640kB free_cma:0kB
[ 40.337567] lowmem_reserve[]: 0 0 9279 9279
[ 40.337666] HighMem free:408kB min:512kB low:15260kB high:30008kB active_anon:1186936kB inactive_anon:0kB active_file:0kB inactive_file:40kB unevictable:0kB writepending:0kB present:1187832kB managed:1187832kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:120kB local_pcp:120kB free_cma:0kB
[ 40.338051] lowmem_reserve[]: 0 0 0 0
[ 40.338159] DMA: 1*4kB (U) 2*8kB (UM) 0*16kB 2*32kB (UM) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 2*1024kB (UM) 1*2048kB (U) 1*4096kB (M) = 8788kB
[ 40.338781] Normal: 11*4kB (U) 14*8kB (UE) 6*16kB (UME) 2*32kB (UM) 0*64kB 1*128kB (E) 2*256kB (ME) 2*512kB (ME) 2*1024kB (ME) 1*2048kB (E) 18*4096kB (UM) = 79804kB
[ 40.339083] HighMem: 2*4kB (U) 2*8kB (UM) 2*16kB (U) 1*32kB (M) 1*64kB (M) 0*128kB 1*256kB (M) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 408kB
[ 40.339563] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=4096kB
[ 40.339724] 39 total pagecache pages
[ 40.339945] 524186 pages RAM
[ 40.340032] 296958 pages HighMem/MovableOnly
[ 40.340380] 8129 pages reserved
[ 40.340526] Out of memory: Kill process 41 (a.out) score 12 or sacrifice child
[ 40.341733] Killed process 41 (a.out) total-vm:2099260kB, anon-rss:26664kB, file-rss:64kB, shmem-rss:0kB
[ 40.351554] clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
[ 40.351854] clocksource: 'acpi_pm' wd_now: ea5383 wd_last: 1125e2 mask: ffffff
[ 40.352083] clocksource: 'tsc' cs_now: 1b2db1039e cs_last: 158b342a09 mask: ffffffffffffffff
[ 40.352476] tsc: Marking TSC unstable due to clocksource watchdog
[ 40.353017] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
[ 40.353325] sched_clock: Marking unstable (40352968436, 26691)<-(40715409249, -362410103)
[ 40.392298] clocksource: Switched to clocksource acpi_pm
[ 40.683413] a.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[ 40.683680] CPU: 0 PID: 131 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 40.683766] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 40.683842] Call Trace:
[ 40.683901] dump_stack+0x16/0x24
[ 40.683959] dump_header+0x64/0x211
[ 40.684016] ? irq_exit+0x2a/0x90
[ 40.684219] ? smp_apic_timer_interrupt+0x45/0x80
[ 40.684356] oom_kill_process+0x1ec/0x400
[ 40.684520] ? has_capability_noaudit+0x1f/0x30
[ 40.684694] ? oom_badness+0xc6/0x140
[ 40.684752] ? oom_evaluate_task+0x14/0xe0
[ 40.684813] out_of_memory+0xe0/0x270
[ 40.684871] __alloc_pages_nodemask+0x6a3/0x830
[ 40.684942] handle_mm_fault+0xa5e/0xdd0
[ 40.685002] ? slow_virt_to_phys+0x2b/0x90
[ 40.685410] __do_page_fault+0x194/0x420
[ 40.685486] ? vmalloc_sync_all+0x150/0x150
[ 40.685692] do_page_fault+0xb/0xd
[ 40.685777] common_exception+0x6d/0x72
[ 40.685848] EIP: 0x8048437
[ 40.685910] EFLAGS: 00000202 CPU: 0
[ 40.685981] EAX: 009f9000 EBX: 7ff00000 ECX: 38876008 EDX: 00000000
[ 40.686533] ESI: 7ff00000 EDI: 00000000 EBP: bfc00b38 ESP: bfc00b00
[ 40.686715] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 40.686831] Mem-Info:
[ 40.686919] active_anon:483543 inactive_anon:0 isolated_anon:0
[ 40.686919] active_file:31 inactive_file:25 isolated_file:35
[ 40.686919] unevictable:0 dirty:0 writeback:0 unstable:0
[ 40.686919] slab_reclaimable:26 slab_unreclaimable:919
[ 40.686919] mapped:83 shmem:0 pagetables:7986 bounce:0
[ 40.686919] free:22233 free_pcp:120 free_cma:0
[ 40.687885] Node 0 active_anon:1934172kB inactive_anon:0kB active_file:124kB inactive_file:100kB unevictable:0kB isolated(anon):0kB isolated(file):140kB mapped:332kB dirty:0kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 40.689342] DMA free:8788kB min:788kB low:984kB high:1180kB active_anon:7128kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 40.689842] lowmem_reserve[]: 0 840 2000 2000
[ 40.689972] Normal free:79744kB min:42744kB low:53428kB high:64112kB active_anon:740068kB inactive_anon:0kB active_file:88kB inactive_file:28kB unevictable:0kB writepending:0kB present:892920kB managed:860480kB mlocked:0kB kernel_stack:2408kB pagetables:31944kB bounce:0kB free_pcp:296kB local_pcp:296kB free_cma:0kB
[ 40.690726] lowmem_reserve[]: 0 0 9279 9279
[ 40.690828] HighMem free:400kB min:512kB low:15260kB high:30008kB active_anon:1186976kB inactive_anon:0kB active_file:36kB inactive_file:72kB unevictable:0kB writepending:0kB present:1187832kB managed:1187832kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:184kB local_pcp:184kB free_cma:0kB
[ 40.691461] lowmem_reserve[]: 0 0 0 0
[ 40.691579] DMA: 1*4kB (U) 2*8kB (UM) 0*16kB 2*32kB (UM) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 2*1024kB (UM) 1*2048kB (U) 1*4096kB (M) = 8788kB
[ 40.691832] Normal: 42*4kB (UM) 35*8kB (UME) 12*16kB (UE) 6*32kB (UM) 1*64kB (M) 2*128kB (ME) 1*256kB (E) 1*512kB (E) 2*1024kB (ME) 1*2048kB (E) 18*4096kB (UM) = 79744kB
[ 40.692432] HighMem: 2*4kB (U) 1*8kB (U) 2*16kB (U) 1*32kB (M) 1*64kB (M) 0*128kB 1*256kB (M) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 400kB
[ 40.692714] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=4096kB
[ 40.692831] 82 total pagecache pages
[ 40.692887] 524186 pages RAM
[ 40.692971] 296958 pages HighMem/MovableOnly
[ 40.693033] 8129 pages reserved
[ 40.693528] Out of memory: Kill process 50 (a.out) score 10 or sacrifice child
[ 40.693705] Killed process 50 (a.out) total-vm:2099260kB, anon-rss:22284kB, file-rss:40kB, shmem-rss:0kB
[ 41.251822] a.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[ 41.252049] CPU: 0 PID: 217 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 41.252139] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 41.252215] Call Trace:
[ 41.252274] dump_stack+0x16/0x24
[ 41.252331] dump_header+0x64/0x211
[ 41.252387] ? irq_exit+0x2a/0x90
[ 41.252500] ? smp_apic_timer_interrupt+0x45/0x80
[ 41.253033] oom_kill_process+0x1ec/0x400
[ 41.253128] ? has_capability_noaudit+0x1f/0x30
[ 41.253220] ? oom_badness+0xc6/0x140
[ 41.253299] ? oom_evaluate_task+0x14/0xe0
[ 41.253374] out_of_memory+0xe0/0x270
[ 41.253489] __alloc_pages_nodemask+0x6a3/0x830
[ 41.253747] handle_mm_fault+0xa5e/0xdd0
[ 41.253825] ? slow_virt_to_phys+0x2b/0x90
[ 41.253897] __do_page_fault+0x194/0x420
[ 41.253985] ? vmalloc_sync_all+0x150/0x150
[ 41.254055] do_page_fault+0xb/0xd
[ 41.254116] common_exception+0x6d/0x72
[ 41.254181] EIP: 0x8048437
[ 41.254228] EFLAGS: 00000202 CPU: 0
[ 41.254357] EAX: 00196000 EBX: 7ff00000 ECX: 37fe4008 EDX: 00000000
[ 41.254764] ESI: 7ff00000 EDI: 00000000 EBP: bfd59aa8 ESP: bfd59a70
[ 41.254917] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 41.255018] Mem-Info:
[ 41.255121] active_anon:483725 inactive_anon:0 isolated_anon:0
[ 41.255121] active_file:0 inactive_file:0 isolated_file:1
[ 41.255121] unevictable:0 dirty:0 writeback:0 unstable:0
[ 41.255121] slab_reclaimable:26 slab_unreclaimable:919
[ 41.255121] mapped:2 shmem:0 pagetables:7936 bounce:0
[ 41.255121] free:22269 free_pcp:60 free_cma:0
[ 41.256137] Node 0 active_anon:1934900kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):4kB mapped:8kB dirty:0kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 41.256637] DMA free:8788kB min:788kB low:984kB high:1180kB active_anon:7128kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 41.257064] lowmem_reserve[]: 0 840 2000 2000
[ 41.257346] Normal free:79808kB min:42744kB low:53428kB high:64112kB active_anon:740620kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:892920kB managed:860480kB mlocked:0kB kernel_stack:2344kB pagetables:31744kB bounce:0kB free_pcp:120kB local_pcp:120kB free_cma:0kB
[ 41.257816] lowmem_reserve[]: 0 0 9279 9279
[ 41.257934] HighMem free:480kB min:512kB low:15260kB high:30008kB active_anon:1187152kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:1187832kB managed:1187832kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:120kB local_pcp:120kB free_cma:0kB
[ 41.258204] lowmem_reserve[]: 0 0 0 0
[ 41.258204] DMA: 1*4kB (U) 2*8kB (UM) 0*16kB 2*32kB (UM) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 2*1024kB (UM) 1*2048kB (U) 1*4096kB (M) = 8788kB
[ 41.259035] Normal: 98*4kB (UM) 43*8kB (UE) 16*16kB (UME) 5*32kB (U) 1*64kB (U) 2*128kB (ME) 2*256kB (ME) 2*512kB (ME) 1*1024kB (E) 1*2048kB (E) 18*4096kB (UM) = 79808kB
[ 41.259312] HighMem: 2*4kB (U) 1*8kB (U) 3*16kB (UM) 1*32kB (M) 0*64kB 1*128kB (M) 1*256kB (M) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 480kB
[ 41.259782] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=4096kB
[ 41.259903] 1 total pagecache pages
[ 41.259975] 524186 pages RAM
[ 41.260022] 296958 pages HighMem/MovableOnly
[ 41.260084] 8129 pages reserved
[ 41.260137] Out of memory: Kill process 53 (a.out) score 10 or sacrifice child
[ 41.260259] Killed process 53 (a.out) total-vm:2099260kB, anon-rss:21276kB, file-rss:8kB, shmem-rss:0kB
[ 42.305105] a.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[ 42.305302] CPU: 0 PID: 224 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 42.305388] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 42.305667] Call Trace:
[ 42.305732] dump_stack+0x16/0x24
[ 42.305790] dump_header+0x64/0x211
[ 42.305847] ? get_page_from_freelist+0x106/0xb30
[ 42.305932] oom_kill_process+0x1ec/0x400
[ 42.305995] ? has_capability_noaudit+0x1f/0x30
[ 42.306060] ? oom_badness+0xc6/0x140
[ 42.306115] ? oom_evaluate_task+0x14/0xe0
[ 42.306175] out_of_memory+0xe0/0x270
[ 42.306231] __alloc_pages_nodemask+0x6a3/0x830
[ 42.306302] handle_mm_fault+0xa5e/0xdd0
[ 42.306361] ? slow_virt_to_phys+0x2b/0x90
[ 42.306485] __do_page_fault+0x194/0x420
[ 42.306725] ? vmalloc_sync_all+0x150/0x150
[ 42.306795] do_page_fault+0xb/0xd
[ 42.306870] common_exception+0x6d/0x72
[ 42.306961] EIP: 0x8048437
[ 42.307003] EFLAGS: 00000202 CPU: 0
[ 42.307053] EAX: 0009c000 EBX: 7e600000 ECX: 37f31008 EDX: 00000000
[ 42.307133] ESI: 7e600000 EDI: 00000000 EBP: bf8660b8 ESP: bf866080
[ 42.307215] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 42.307287] Mem-Info:
[ 42.307391] active_anon:483682 inactive_anon:0 isolated_anon:0
[ 42.307391] active_file:0 inactive_file:3 isolated_file:17
[ 42.307391] unevictable:0 dirty:1 writeback:0 unstable:0
[ 42.307391] slab_reclaimable:26 slab_unreclaimable:919
[ 42.307391] mapped:17 shmem:0 pagetables:7904 bounce:0
[ 42.307391] free:22274 free_pcp:125 free_cma:0
[ 42.308066] Node 0 active_anon:1934728kB inactive_anon:0kB active_file:0kB inactive_file:12kB unevictable:0kB isolated(anon):0kB isolated(file):68kB mapped:68kB dirty:4kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 42.308390] DMA free:8788kB min:788kB low:984kB high:1180kB active_anon:7128kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 42.308810] lowmem_reserve[]: 0 840 2000 2000
[ 42.308948] Normal free:79832kB min:42744kB low:53428kB high:64112kB active_anon:740776kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:892920kB managed:860480kB mlocked:0kB kernel_stack:2328kB pagetables:31616kB bounce:0kB free_pcp:124kB local_pcp:124kB free_cma:0kB
[ 42.309038] lowmem_reserve[]: 0 0 9279 9279
[ 42.309823] HighMem free:476kB min:512kB low:15260kB high:30008kB active_anon:1186824kB inactive_anon:0kB active_file:0kB inactive_file:12kB unevictable:0kB writepending:4kB present:1187832kB managed:1187832kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:376kB local_pcp:376kB free_cma:0kB
[ 42.310231] lowmem_reserve[]: 0 0 0 0
[ 42.310338] DMA: 1*4kB (U) 2*8kB (UM) 0*16kB 2*32kB (UM) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 2*1024kB (UM) 1*2048kB (U) 1*4096kB (M) = 8788kB
[ 42.310838] Normal: 104*4kB (U) 47*8kB (UME) 18*16kB (UME) 7*32kB (U) 1*64kB (U) 1*128kB (E) 2*256kB (ME) 2*512kB (ME) 1*1024kB (E) 1*2048kB (E) 18*4096kB (UM) = 79832kB
[ 42.311455] HighMem: 3*4kB (UM) 2*8kB (UM) 2*16kB (U) 1*32kB (M) 0*64kB 1*128kB (M) 1*256kB (M) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 476kB
[ 42.311775] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=4096kB
[ 42.311935] 20 total pagecache pages
[ 42.312011] 524186 pages RAM
[ 42.312090] 296958 pages HighMem/MovableOnly
[ 42.312319] 8129 pages reserved
[ 42.312413] Out of memory: Kill process 36 (a.out) score 9 or sacrifice child
[ 42.312583] Killed process 36 (a.out) total-vm:2099260kB, anon-rss:21080kB, file-rss:4kB, shmem-rss:0kB
[ 42.366107] BUG: unable to handle kernel NULL pointer dereference at 00000200
[ 42.366346] IP: mpage_readpages+0x8b/0x160
[ 42.366431] *pde = 00000000
[ 42.366599] Oops: 0000 [#1] DEBUG_PAGEALLOC
[ 42.366599] CPU: 0 PID: 308 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 42.366599] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 42.366599] EIP: mpage_readpages+0x8b/0x160
[ 42.366599] EFLAGS: 00000206 CPU: 0
[ 42.366599] EAX: d85afe28 EBX: 00000200 ECX: d85afe30 EDX: 00000100
[ 42.366599] ESI: 00000011 EDI: 000001ec EBP: d85afdf0 ESP: d85afd74
[ 42.366599] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 42.366599] CR0: 80050033 CR2: 00000200 CR3: 185a0000 CR4: 000006d0
[ 42.366599] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 42.366599] DR6: 00000000 DR7: 00000000
[ 42.366599] Call Trace:
[ 42.366599] ? xfs_setfilesize_trans_alloc.isra.29+0x80/0x80
[ 42.366599] ? xfs_setfilesize_trans_alloc.isra.29+0x80/0x80
[ 42.366599] ? __radix_tree_lookup+0x6e/0xd0
[ 42.366599] ? xfs_map_at_offset+0x30/0x30
[ 42.366599] xfs_vm_readpages+0x19/0x20
[ 42.366599] ? xfs_setfilesize_trans_alloc.isra.29+0x80/0x80
[ 42.366599] __do_page_cache_readahead+0x158/0x1f0
[ 42.366599] filemap_fault+0x299/0x510
[ 42.366599] ? page_add_file_rmap+0xfb/0x150
[ 42.366599] ? unlock_page+0x30/0x30
[ 42.366599] ? filemap_map_pages+0x265/0x2e0
[ 42.366599] __xfs_filemap_fault.isra.18+0x2d/0xb0
[ 42.366599] xfs_filemap_fault+0xa/0x10
[ 42.366599] __do_fault+0x11/0x30
[ 42.366599] ? unlock_page+0x30/0x30
[ 42.366599] handle_mm_fault+0x7d4/0xdd0
[ 42.366599] __do_page_fault+0x194/0x420
[ 42.366599] ? vmalloc_sync_all+0x150/0x150
[ 42.366599] do_page_fault+0xb/0xd
[ 42.366599] common_exception+0x6d/0x72
[ 42.366599] EIP: 0xb7efd1e0
[ 42.366599] EFLAGS: 00000246 CPU: 0
[ 42.366599] EAX: b7e42790 EBX: b7f85000 ECX: bfe5d02c EDX: bfe5d030
[ 42.366599] ESI: 00000000 EDI: b7f85404 EBP: bfe5d058 ESP: bfe5cffc
[ 42.366599] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 42.366599] Code: 00 00 eb 1a 8d 74 26 00 8b 03 a8 01 0f 85 cc 00 00 00 89 f8 ff 48 10 74 77 83 ee 01 74 7c 8b 45 a4 8b 58 04 8d 7b ec 8d 74 26 00 <8b> 13 8b 43 04 89 42 04 89 10 8b 45 a8 8b 4b f4 8b 55 a0 c7 03
[ 42.366599] EIP: mpage_readpages+0x8b/0x160 SS:ESP: 0068:d85afd74
[ 42.366599] CR2: 0000000000000200
[ 42.371210] ---[ end trace c88beaeceebe4c9b ]---
[ 42.371357] Kernel panic - not syncing: Fatal exception
[ 42.371508] Kernel Offset: disabled
[ 42.371617] Rebooting in 1 seconds..
Another example is shown below.
[ 31.067600] BUG: Bad page state in process a.out pfn:7fe84
[ 31.067817] page:f63884a0 count:0 mapcount:2 mapping:f5818f94 index:0x1
[ 31.067955] flags: 0x7e000000()
[ 31.068198] raw: 7e000000 f5818f94 00000001 00000001 00000000 00000100 00000200 00000000
[ 31.068198] raw: 00000000 00000000
[ 31.068198] page dumped because: non-NULL mapping
[ 31.068198] CPU: 0 PID: 47 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 31.068198] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 31.068198] Call Trace:
[ 31.068198] dump_stack+0x16/0x24
[ 31.068198] bad_page+0x106/0x122
[ 31.068198] free_pages_check_bad+0x5b/0x5e
[ 31.068198] free_pcppages_bulk+0x3c4/0x3d0
[ 31.068198] free_unref_page_commit.isra.117+0x6c/0x80
[ 31.068198] free_unref_page_list+0xd9/0x110
[ 31.068198] release_pages+0x208/0x2c0
[ 31.068198] tlb_flush_mmu_free+0x2f/0x50
[ 31.068198] arch_tlb_finish_mmu+0x30/0x60
[ 31.068198] tlb_finish_mmu+0x24/0x40
[ 31.068198] exit_mmap+0x99/0x130
[ 31.068198] mmput+0x36/0xb0
[ 31.068198] do_exit+0x199/0x8d0
[ 31.068198] ? recalc_sigpending+0x11/0x40
[ 31.068198] ? __alloc_pages_nodemask+0x1d8/0x830
[ 31.068198] do_group_exit+0x2a/0x70
[ 31.068198] get_signal+0x121/0x460
[ 31.068198] ? ktime_get+0x47/0xf0
[ 31.068198] do_signal+0x24/0x590
[ 31.068198] ? native_sched_clock+0x35/0x100
[ 31.068198] ? __phys_addr+0x32/0x70
[ 31.068198] ? __schedule+0x126/0x36b
[ 31.068198] ? __do_page_fault+0x1b0/0x420
[ 31.068198] exit_to_usermode_loop+0x32/0x5e
[ 31.068198] ? vmalloc_sync_all+0x150/0x150
[ 31.068198] prepare_exit_to_usermode+0x43/0x70
[ 31.068198] ? vmalloc_sync_all+0x150/0x150
[ 31.068198] resume_userspace+0x8/0xd
[ 31.068198] EIP: 0x8048437
[ 31.068198] EFLAGS: 00000202 CPU: 0
[ 31.068198] EAX: 01659000 EBX: 7ff00000 ECX: 394f7008 EDX: 00000000
[ 31.068198] ESI: 7ff00000 EDI: 00000000 EBP: bff1d698 ESP: bff1d660
[ 31.068198] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 31.068198] Disabling lock debugging due to kernel taint
Yet another example is shown below.
[ 28.211801] BUG: unable to handle kernel paging request at 1a8a306a
[ 28.212034] IP: page_remove_rmap+0x17/0x280
[ 28.212269] *pde = 00000000
[ 28.212447] Oops: 0000 [#1] DEBUG_PAGEALLOC
[ 28.212614] CPU: 0 PID: 54 Comm: a.out Not tainted 4.15.0-rc7+ #220
[ 28.212767] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 28.212901] EIP: page_remove_rmap+0x17/0x280
[ 28.212981] EFLAGS: 00000206 CPU: 0
[ 28.213061] EAX: 1a8a3066 EBX: f52c2210 ECX: 00000051 EDX: 00000000
[ 28.213203] ESI: 148da045 EDI: f63884c8 EBP: f5ea1b10 ESP: f5ea1b04
[ 28.213410] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 28.213562] CR0: 80050033 CR2: 1a8a306a CR3: 35404000 CR4: 000006d0
[ 28.213762] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 28.213942] DR6: 00000000 DR7: 00000000
[ 28.214082] Call Trace:
[ 28.214228] try_to_unmap_one+0x1ca/0x410
[ 28.214341] rmap_walk_file+0xf0/0x1e0
[ 28.214433] rmap_walk+0x32/0x60
[ 28.214524] try_to_unmap+0x4d/0xd0
[ 28.214608] ? page_remove_rmap+0x280/0x280
[ 28.214715] ? page_not_mapped+0x10/0x10
[ 28.214816] ? page_get_anon_vma+0x80/0x80
[ 28.214918] shrink_page_list+0x293/0xcd0
[ 28.215037] shrink_inactive_list+0x1a3/0x450
[ 28.215137] shrink_node_memcg+0x2b0/0x350
[ 28.215263] shrink_node+0xbb/0x2c0
[ 28.215370] do_try_to_free_pages+0x92/0x2c0
[ 28.215480] try_to_free_pages+0x1fb/0x320
[ 28.215589] __alloc_pages_nodemask+0x351/0x830
[ 28.215689] ? tick_program_event+0x3a/0x80
[ 28.215853] ? SyS_readahead+0xa0/0xa0
[ 28.215957] ? mem_cgroup_commit_charge+0x6e/0xb0
[ 28.216068] ? page_add_new_anon_rmap+0x6c/0xa0
[ 28.216202] handle_mm_fault+0xa5e/0xdd0
[ 28.216304] __do_page_fault+0x194/0x420
[ 28.216396] ? vmalloc_sync_all+0x150/0x150
[ 28.216498] do_page_fault+0xb/0xd
[ 28.216591] common_exception+0x6d/0x72
[ 28.216697] EIP: 0x8048437
[ 28.216766] EFLAGS: 00000202 CPU: 0
[ 28.216843] EAX: 01267000 EBX: 7ff00000 ECX: 3910e008 EDX: 00000000
[ 28.216981] ESI: 7ff00000 EDI: 00000000 EBP: bfc0cf08 ESP: bfc0ced0
[ 28.217098] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 28.217199] Code: b1 83 e8 01 e9 55 ff ff ff 83 e8 01 e9 37 ff ff ff 8d 76 00 55 89 e5 56 53 89 c3 83 ec 04 8b 40 14 a8 01 0f 85 10 02 00 00 89 d8 <f6> 40 04 01 74 6b 84 d2 0f 85 5b 01 00 00 83 43 0c ff 78 0d 83
[ 28.217849] EIP: page_remove_rmap+0x17/0x280 SS:ESP: 0068:f5ea1b04
[ 28.217973] CR2: 000000001a8a306a
[ 28.218377] ---[ end trace 118e4d2be9e69f8a ]---
[ 28.218661] Kernel panic - not syncing: Fatal exception
[ 28.218808] Kernel Offset: disabled
[ 28.218931] Rebooting in 1 seconds..
On Sun, Jan 14, 2018 at 3:54 AM, Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp> wrote: > This memory corruption bug occurs even on CONFIG_SMP=n CONFIG_PREEMPT_NONE=y > kernel. This bug highly depends on timing and thus too difficult to bisect. > This bug seems to exist at least since Linux 4.8 (judging from the traces, though > the cause might be different). None of debugging configuration gives me a clue. > So far only CONFIG_HIGHMEM=y CONFIG_DEBUG_PAGEALLOC=y kernel (with RAM enough to > use HighMem: zone) seems to hit this bug, but it might be just by chance caused > by timings. Thus, there is no evidence that 64bit kernels are not affected by > this bug. But I can't narrow down any more. Thus, I call for developers who can > narrow down / identify where the memory corruption bug is. Hmm. I guess I'm still hung up on the "it does not look like a valid 'struct page *'" thing. Can you reproduce this with CONFIG_FLATMEM=y instead of CONFIG_SPARSEMEM? Because if you can, I think we can easily add a few more pfn and 'struct page' validation debug statements. With SPARSEMEM, it gets pretty complicated because the whole struct page setup is much more complex. Linus
Linus Torvalds wrote: > On Sun, Jan 14, 2018 at 3:54 AM, Tetsuo Handa > <penguin-kernel@i-love.sakura.ne.jp> wrote: > > This memory corruption bug occurs even on CONFIG_SMP=n CONFIG_PREEMPT_NONE=y > > kernel. This bug highly depends on timing and thus too difficult to bisect. > > This bug seems to exist at least since Linux 4.8 (judging from the traces, though > > the cause might be different). None of debugging configuration gives me a clue. > > So far only CONFIG_HIGHMEM=y CONFIG_DEBUG_PAGEALLOC=y kernel (with RAM enough to > > use HighMem: zone) seems to hit this bug, but it might be just by chance caused > > by timings. Thus, there is no evidence that 64bit kernels are not affected by > > this bug. But I can't narrow down any more. Thus, I call for developers who can > > narrow down / identify where the memory corruption bug is. > > Hmm. > > I guess I'm still hung up on the "it does not look like a valid > 'struct page *'" thing. > > Can you reproduce this with CONFIG_FLATMEM=y instead of CONFIG_SPARSEMEM? > > Because if you can, I think we can easily add a few more pfn and > 'struct page' validation debug statements. With SPARSEMEM, it gets > pretty complicated because the whole struct page setup is much more > complex. I can't reproduce this with CONFIG_FLATMEM=y . But I'm not sure whether we are hitting a bug in CONFIG_SPARSEMEM=y code, for the bug is highly timing dependent. ---------- # diff .config.old .config 372a373 > CONFIG_X86_SUPPORTS_MEMORY_FAILURE=y 462d462 < CONFIG_NEED_NODE_MEMMAP_SIZE=y 468,471c468,471 < # CONFIG_FLATMEM_MANUAL is not set < CONFIG_SPARSEMEM_MANUAL=y < CONFIG_SPARSEMEM=y < CONFIG_HAVE_MEMORY_PRESENT=y --- > CONFIG_FLATMEM_MANUAL=y > # CONFIG_SPARSEMEM_MANUAL is not set > CONFIG_FLATMEM=y > CONFIG_FLAT_NODE_MEM_MAP=y 478d477 < # CONFIG_MEMORY_HOTPLUG is not set 486a486,487 > CONFIG_ARCH_SUPPORTS_MEMORY_FAILURE=y > # CONFIG_MEMORY_FAILURE is not set ---------- ---------- [ 0.000000] Linux version 4.15.0-rc8 (root@localhost.localdomain) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC)) #381 Tue Jan 16 09:38:22 JST 2018 [ 0.000000] x86/fpu: x87 FPU will use FXSAVE [ 0.000000] e820: BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffbfff] usable [ 0.000000] BIOS-e820: [mem 0x000000007fffc000-0x000000007fffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] Notice: NX (Execute Disable) protection missing in CPU! [ 0.000000] random: fast init done [ 0.000000] SMBIOS 2.4 present. [ 0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011 [ 0.000000] e820: last_pfn = 0x7fffc max_arch_pfn = 0x100000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- UC [ 0.000000] found SMP MP-table at [mem 0x000f7300-0x000f730f] mapped at [(ptrval)] [ 0.000000] Scanning 1 areas for low memory corruption [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F7160 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x000000007FFFFA9B 000030 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x000000007FFFF177 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x000000007FFFE040 001137 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x000000007FFFE000 000040 [ 0.000000] ACPI: SSDT 0x000000007FFFF1EB 000838 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: APIC 0x000000007FFFFA23 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001) [ 0.000000] 1159MB HIGHMEM available. [ 0.000000] 887MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 377fe000 [ 0.000000] low ram: 0 - 377fe000 [ 0.000000] tsc: Fast TSC calibration using PIT [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x00000000377fdfff] [ 0.000000] HighMem [mem 0x00000000377fe000-0x000000007fffbfff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x000000007fffbfff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffbfff] [ 0.000000] Reserved but unavailable: 98 pages [ 0.000000] Using APIC driver default [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0 already used, trying 1 [ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] e820: [mem 0x80000000-0xfffbffff] available for PCI devices [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 521966 [ 0.000000] Kernel command line: ro console=ttyS0,115200n8 root=/dev/vda init=/init [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Initializing CPU#0 [ 0.000000] Initializing HighMem for node 0 (000377fe:0007fffc) [ 0.000000] Initializing Movable for node 0 (00000000:00000000) [ 0.000000] Memory: 2064192K/2096744K available (3353K kernel code, 256K rwdata, 924K rodata, 376K init, 5308K bss, 32552K reserved, 0K cma-reserved, 1187832K highmem) [ 0.000000] virtual kernel memory layout: [ 0.000000] fixmap : 0xfffa4000 - 0xfffff000 ( 364 kB) [ 0.000000] cpu_entry : 0xffc00000 - 0xffc28000 ( 160 kB) [ 0.000000] pkmap : 0xff800000 - 0xffc00000 (4096 kB) [ 0.000000] vmalloc : 0xf7ffe000 - 0xff7fe000 ( 120 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf77fe000 ( 887 MB) [ 0.000000] .init : 0xc147e000 - 0xc14dc000 ( 376 kB) [ 0.000000] .data : 0xc13466c8 - 0xc14713e0 (1195 kB) [ 0.000000] .text : 0xc1000000 - 0xc13466c8 (3353 kB) [ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok. [ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] NR_IRQS: 2304, nr_irqs: 256, preallocated irqs: 16 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [ttyS0] enabled [ 0.000000] ACPI: Core revision 20170831 [ 0.000000] ACPI: 2 ACPI AML tables successfully acquired and loaded [ 0.001000] APIC: Switch to symmetric I/O mode setup [ 0.002000] Enabling APIC mode: Flat. Using 1 I/O APICs [ 0.002000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] tsc: Fast TSC calibration using PIT [ 0.008000] tsc: Detected 1995.399 MHz processor [ 0.008000] Calibrating delay loop (skipped), value calculated using timer frequency.. 3990.79 BogoMIPS (lpj=1995399) [ 0.008000] pid_max: default: 32768 minimum: 301 [ 0.009788] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.010000] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.017000] mce: CPU supports 10 MCE banks [ 0.017478] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.017644] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.017792] CPU: Intel Common 32-bit KVM processor (family: 0xf, model: 0x6, stepping: 0x1) [ 0.018000] Spectre V2 mitigation: Vulnerable: Minimal generic ASM retpoline [ 0.024000] Performance Events: unsupported Netburst CPU model 6 no PMU driver, software events only. [ 0.027000] APIC calibration not consistent with PM-Timer: 205ms instead of 100ms [ 0.027000] APIC delta adjusted to PM-Timer: 6250051 (12854429) [ 0.029058] devtmpfs: initialized [ 0.032000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.032000] futex hash table entries: 256 (order: -1, 3072 bytes) [ 0.035992] cpuidle: using governor menu [ 0.037000] ACPI: bus type PCI registered [ 0.039000] PCI: PCI BIOS revision 2.10 entry at 0xfd54b, last bus=0 [ 0.039000] PCI: Using configuration type 1 for base access [ 0.048000] HugeTLB registered 4.00 MiB page size, pre-allocated 0 pages [ 0.050000] ACPI: Added _OSI(Module Device) [ 0.050000] ACPI: Added _OSI(Processor Device) [ 0.050000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.050000] ACPI: Added _OSI(Processor Aggregator Device) [ 0.071000] ACPI: Interpreter enabled [ 0.071000] ACPI: (supports S0 S5) [ 0.071000] ACPI: Using IOAPIC for interrupt routing [ 0.071409] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.073000] ACPI: Enabled 16 GPEs in block 00 to 0F [ 0.100000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.100000] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI] [ 0.100314] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM [ 0.100785] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.102000] PCI host bridge to bus 0000:00 [ 0.102156] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.102378] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.102602] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.102784] pci_bus 0000:00: root bus resource [mem 0x80000000-0xfebfffff window] [ 0.103000] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.108493] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.108716] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.108905] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.109000] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.110000] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.110000] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.129000] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) [ 0.130000] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) [ 0.130000] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) [ 0.131000] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) [ 0.131000] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) [ 0.135000] pci 0000:00:02.0: vgaarb: setting as boot VGA device [ 0.135000] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none [ 0.135000] pci 0000:00:02.0: vgaarb: bridge control possible [ 0.135000] vgaarb: loaded [ 0.136000] SCSI subsystem initialized [ 0.136735] PCI: Using ACPI for IRQ routing [ 0.137652] clocksource: Switched to clocksource refined-jiffies [ 0.138999] ACPI: Failed to create genetlink family for ACPI event [ 0.138999] pnp: PnP ACPI init [ 0.142999] pnp: PnP ACPI: found 5 devices [ 0.167133] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.167414] clocksource: Switched to clocksource acpi_pm [ 0.167995] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.167995] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.167995] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.170867] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] [ 0.179490] Scanning for low memory corruption every 60 seconds [ 0.185037] workingset: timestamp_bits=14 max_order=19 bucket_order=5 [ 0.209598] zbud: loaded [ 0.214606] SGI XFS with ACLs, security attributes, no debug enabled [ 0.226422] bounce: pool size: 64 pages [ 0.226745] io scheduler noop registered (default) [ 0.239185] atomic64_test: passed for i586+ platform with CX8 and with SSE [ 0.245995] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 0.246746] ACPI: Power Button [PWRF] [ 0.259029] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11 [ 0.259249] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver [ 0.263351] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 0.286776] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 0.293723] Non-volatile memory driver v1.3 [ 0.330628] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 0.335343] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 0.335644] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 0.338091] Using IPI Shortcut mode [ 0.338091] sched_clock: Marking stable (337091080, 0)->(767486575, -430395495) [ 0.341662] page_owner is disabled [ 0.373592] XFS (vda): Mounting V5 Filesystem [ 0.440300] XFS (vda): Ending clean mount [ 0.463216] VFS: Mounted root (xfs filesystem) readonly on device 254:0. [ 0.465860] devtmpfs: mounted [ 0.466592] debug: unmapping init [mem 0xc147e000-0xc14dbfff] [ 0.468584] Write protecting the kernel text: 3356k [ 0.469119] Write protecting the kernel read-only data: 936k Starting a.out [ 1.184517] tsc: Refined TSC clocksource calibration: 1995.468 MHz [ 1.184906] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x3986e9f5ad2, max_idle_ns: 881590531620 ns [ 2.259952] clocksource: Switched to clocksource tsc ---------- I dont know why but selecting CONFIG_FLATMEM=y seems to avoid a different bug where bootup of qemu randomly fails at ---------- [ 0.000000] Linux version 4.15.0-rc8 (root@localhost.localdomain) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC)) #380 Tue Jan 16 09:25:52 JST 2018 [ 0.000000] x86/fpu: x87 FPU will use FXSAVE [ 0.000000] e820: BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffbfff] usable [ 0.000000] BIOS-e820: [mem 0x000000007fffc000-0x000000007fffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] Notice: NX (Execute Disable) protection missing in CPU! [ 0.000000] random: fast init done [ 0.000000] SMBIOS 2.4 present. [ 0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011 [ 0.000000] e820: last_pfn = 0x7fffc max_arch_pfn = 0x100000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- UC [ 0.000000] found SMP MP-table at [mem 0x000f7300-0x000f730f] mapped at [(ptrval)] [ 0.000000] Scanning 1 areas for low memory corruption [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F7160 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x000000007FFFFA9B 000030 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x000000007FFFF177 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x000000007FFFE040 001137 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x000000007FFFE000 000040 [ 0.000000] ACPI: SSDT 0x000000007FFFF1EB 000838 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: APIC 0x000000007FFFFA23 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001) [ 0.000000] 1159MB HIGHMEM available. [ 0.000000] 887MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 377fe000 [ 0.000000] low ram: 0 - 377fe000 [ 0.000000] tsc: Unable to calibrate against PIT [ 0.000000] tsc: No reference (HPET/PMTIMER) available [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x00000000377fdfff] [ 0.000000] HighMem [mem 0x00000000377fe000-0x000000007fffbfff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x000000007fffbfff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffbfff] [ 0.000000] Reserved but unavailable: 98 pages [ 0.000000] Using APIC driver default [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0 already used, trying 1 [ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] e820: [mem 0x80000000-0xfffbffff] available for PCI devices [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 521966 [ 0.000000] Kernel command line: ro console=ttyS0,115200n8 root=/dev/vda init=/init [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Initializing CPU#0 [ 0.000000] Initializing HighMem for node 0 (000377fe:0007fffc) [ 0.000000] Initializing Movable for node 0 (00000000:00000000) [ 0.000000] Memory: 2064188K/2096744K available (3357K kernel code, 252K rwdata, 924K rodata, 380K init, 5308K bss, 32556K reserved, 0K cma-reserved, 1187832K highmem) [ 0.000000] virtual kernel memory layout: [ 0.000000] fixmap : 0xfffa4000 - 0xfffff000 ( 364 kB) [ 0.000000] cpu_entry : 0xffc00000 - 0xffc28000 ( 160 kB) [ 0.000000] pkmap : 0xff800000 - 0xffc00000 (4096 kB) [ 0.000000] vmalloc : 0xf7ffe000 - 0xff7fe000 ( 120 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf77fe000 ( 887 MB) [ 0.000000] .init : 0xc147e000 - 0xc14dd000 ( 380 kB) [ 0.000000] .data : 0xc13476a8 - 0xc14713e0 (1191 kB) [ 0.000000] .text : 0xc1000000 - 0xc13476a8 (3357 kB) [ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok. [ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] NR_IRQS: 2304, nr_irqs: 256, preallocated irqs: 16 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [ttyS0] enabled [ 0.000000] ACPI: Core revision 20170831 [ 0.000000] ACPI: 2 ACPI AML tables successfully acquired and loaded [ 0.000000] APIC: Switch to symmetric I/O mode setup [ 0.000000] Enabling APIC mode: Flat. Using 1 I/O APICs [ 0.000000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.000000] ..MP-BIOS bug: 8254 timer not connected to IO-APIC [ 0.000000] ...trying to set up timer (IRQ0) through the 8259A ... [ 0.000000] ..... (found apic 0 pin 2) ... [ 0.000000] ....... failed. [ 0.000000] ...trying to set up timer as Virtual Wire IRQ... [ 0.000000] ..... failed. [ 0.000000] ...trying to set up timer as ExtINT IRQ... [ 0.000000] ..... failed :(. [ 0.000000] Kernel panic - not syncing: IO-APIC + timer doesn't work! Boot with apic=debug and send a report. Then try booting with the 'noapic' option. [ 0.000000] [ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.15.0-rc8 #380 [ 0.000000] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011 [ 0.000000] Call Trace: [ 0.000000] dump_stack+0x16/0x24 [ 0.000000] panic+0x87/0x1a2 [ 0.000000] ? vprintk_func+0x23/0x60 [ 0.000000] setup_IO_APIC+0x4dd/0x6f8 [ 0.000000] ? clear_IO_APIC+0x29/0x50 [ 0.000000] ? lapic_get_maxlvt+0x2e/0x40 [ 0.000000] ? end_local_APIC_setup+0x9d/0x130 [ 0.000000] apic_bsp_setup+0x70/0x75 [ 0.000000] apic_intr_mode_init+0x10c/0x10e [ 0.000000] ? hpet_time_init+0x1e/0x20 [ 0.000000] x86_late_time_init+0xf/0x16 [ 0.000000] start_kernel+0x2ef/0x360 [ 0.000000] ? set_init_arg+0x52/0x52 [ 0.000000] i386_start_kernel+0x13d/0x140 [ 0.000000] startup_32_smp+0x164/0x168 [ 0.000000] Rebooting in 1 seconds.. ---------- or hangs at ---------- [ 0.000000] Linux version 4.15.0-rc8 (root@localhost.localdomain) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC)) #380 Tue Jan 16 09:25:52 JST 2018 [ 0.000000] x86/fpu: x87 FPU will use FXSAVE [ 0.000000] e820: BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffbfff] usable [ 0.000000] BIOS-e820: [mem 0x000000007fffc000-0x000000007fffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] Notice: NX (Execute Disable) protection missing in CPU! [ 0.000000] random: fast init done [ 0.000000] SMBIOS 2.4 present. [ 0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011 [ 0.000000] e820: last_pfn = 0x7fffc max_arch_pfn = 0x100000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- UC [ 0.000000] found SMP MP-table at [mem 0x000f7300-0x000f730f] mapped at [(ptrval)] [ 0.000000] Scanning 1 areas for low memory corruption [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F7160 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x000000007FFFFA9B 000030 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x000000007FFFF177 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x000000007FFFE040 001137 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x000000007FFFE000 000040 [ 0.000000] ACPI: SSDT 0x000000007FFFF1EB 000838 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001) [ 0.000000] ACPI: APIC 0x000000007FFFFA23 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001) [ 0.000000] 1159MB HIGHMEM available. [ 0.000000] 887MB LOWMEM available. [ 0.000000] mapped low ram: 0 - 377fe000 [ 0.000000] low ram: 0 - 377fe000 [ 0.000000] tsc: Unable to calibrate against PIT [ 0.000000] tsc: No reference (HPET/PMTIMER) available [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] Normal [mem 0x0000000001000000-0x00000000377fdfff] [ 0.000000] HighMem [mem 0x00000000377fe000-0x000000007fffbfff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x000000007fffbfff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffbfff] [ 0.000000] Reserved but unavailable: 98 pages [ 0.000000] Using APIC driver default [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0 already used, trying 1 [ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] e820: [mem 0x80000000-0xfffbffff] available for PCI devices [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 521966 [ 0.000000] Kernel command line: ro console=ttyS0,115200n8 root=/dev/vda init=/init [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Initializing CPU#0 [ 0.000000] Initializing HighMem for node 0 (000377fe:0007fffc) [ 0.000000] Initializing Movable for node 0 (00000000:00000000) [ 0.000000] Memory: 2064188K/2096744K available (3357K kernel code, 252K rwdata, 924K rodata, 380K init, 5308K bss, 32556K reserved, 0K cma-reserved, 1187832K highmem) [ 0.000000] virtual kernel memory layout: [ 0.000000] fixmap : 0xfffa4000 - 0xfffff000 ( 364 kB) [ 0.000000] cpu_entry : 0xffc00000 - 0xffc28000 ( 160 kB) [ 0.000000] pkmap : 0xff800000 - 0xffc00000 (4096 kB) [ 0.000000] vmalloc : 0xf7ffe000 - 0xff7fe000 ( 120 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf77fe000 ( 887 MB) [ 0.000000] .init : 0xc147e000 - 0xc14dd000 ( 380 kB) [ 0.000000] .data : 0xc13476a8 - 0xc14713e0 (1191 kB) [ 0.000000] .text : 0xc1000000 - 0xc13476a8 (3357 kB) [ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok. [ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] NR_IRQS: 2304, nr_irqs: 256, preallocated irqs: 16 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [ttyS0] enabled [ 0.000000] ACPI: Core revision 20170831 [ 0.000000] ACPI: 2 ACPI AML tables successfully acquired and loaded [ 0.001000] APIC: Switch to symmetric I/O mode setup [ 0.001000] Enabling APIC mode: Flat. Using 1 I/O APICs [ 0.001000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.003000] ..MP-BIOS bug: 8254 timer not connected to IO-APIC [ 0.003000] ...trying to set up timer (IRQ0) through the 8259A ... [ 0.003000] ..... (found apic 0 pin 2) ... [ 0.005000] ....... failed. [ 0.005000] ...trying to set up timer as Virtual Wire IRQ... [ 13.120000] random: crng init done ---------- which has been bothering me when testing using qemu. Note that the 13.120000 part is incorrect. There is no delay between "...trying to set up timer as Virtual Wire IRQ..." line and "random: crng init done" line.
On Mon, Jan 15, 2018 at 5:15 PM, Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp> wrote: > > I can't reproduce this with CONFIG_FLATMEM=y . But I'm not sure whether > we are hitting a bug in CONFIG_SPARSEMEM=y code, for the bug is highly > timing dependent. Hmm. Maybe. But sparsemem really also generates *much* more complex code particularly for the pfn_to_page() case. It also has much less testing. For example, on x86-64 we do use sparsemem, but we use the VMEMMAP version of sparsemem: the version that does *not* play really odd and complex games with that whole pfn_to_page(). I've always felt like sparsemem was really damn complicated. The whole "section_mem_map" encoding is really subtle and odd. And considering that we're getting what appears to be a invalid page, in one of the more complicated sequences that very much does that whole pfn_to_page(), I really wonder. I wonder if somebody could add some VM_BUG_ON() checks to the non-vmemmap case of sparsemem in include/asm-generic/memory_model.h. Because this: #define __pfn_to_page(pfn) \ ({ unsigned long __pfn = (pfn); \ struct mem_section *__sec = __pfn_to_section(__pfn); \ __section_mem_map_addr(__sec) + __pfn; \ }) is really subtle, and if we have some case where we pass in an out-of-range pfn, or some case where we get the section wrong (because the pfn is between sections or whatever due to some subtle setup bug), things will really go sideways. The reason I was hoping you could do this for FLATMEM is that it's much easier to verify the pfn range in that case. The sparsemem cases really makes it much nastier. That said, all of that code is really old. Most of it goes back to -05/06 or so. But since you seem to be able to reproduce at least back to 4.8, I guess this bug does back years too. But I'm adding Dave Hansen explicitly to the cc, in case he has any ideas. Not because I blame him, but he's touched the sparsemem code fairly recently, so maybe he'd have some idea on adding sanity checking to the sparsemem version of pfn_to_page(). > I dont know why but selecting CONFIG_FLATMEM=y seems to avoid a different bug > where bootup of qemu randomly fails at Hmm. That looks very different indeed. But if CONFIG_SPARSEMEM (presumably together with HIGHMEM) has some odd off-by-one corner case or similar, who knows *what* issues it could trigger. Linus
On 01/15/2018 06:14 PM, Linus Torvalds wrote: > But I'm adding Dave Hansen explicitly to the cc, in case he has any > ideas. Not because I blame him, but he's touched the sparsemem code > fairly recently, so maybe he'd have some idea on adding sanity > checking to the sparsemem version of pfn_to_page(). I swear I haven't touched it lately! I'm not sure I'd go after pfn_to_page(). *Maybe* if we were close to the places where we've done a pfn_to_page(), but I'm not seeing those. These, for instance (from the January 5th post) have sane (~500MB) PFNs and all BUG_ON() because of seeing the page being locked at free: [ 192.152510] BUG: Bad page state in process a.out pfn:18566 [ 77.872133] BUG: Bad page state in process a.out pfn:1873a [ 188.992549] BUG: Bad page state in process a.out pfn:197ea and the page in all those cases came off a list, not out of a pte or something that would need pfn_to_page(). The page fault path leading up to the "EIP is at page_cache_tree_insert+0xbe/0xc0" probably doesn't have a pfn_to_page() anywhere in there at all. Did anyone else notice the [ 31.068198] ? vmalloc_sync_all+0x150/0x150 present in a bunch of the stack traces? That should be pretty uncommon. Is it just part of the normal do_page_fault() stack and the stack dumper picks up on it? A few things from earlier in this thread: > [ 44.103192] page:5a5a0697 count:-1055023618 mapcount:-1055030029 mapping:26f4be11 index:0xc11d7c83 > [ 44.103196] flags: 0xc10528fe(waiters|error|referenced|uptodate|dirty|lru|active|reserved|private_2|mappedtodisk|swapbacked) > [ 44.103200] raw: c10528fe c114fff7 c11d7c83 c11d84f2 c11d9dfe c11daa34 c11daaa0 c13e65df > [ 44.103201] raw: c13e4a1c c13e4c62 > [ 44.103202] page dumped because: VM_BUG_ON_PAGE(page_ref_count(page) <= 0) > [ 44.103203] page->mem_cgroup:35401b27 Isn't that 'page:' a non-aligned address in userspace? It's also weird that you start dumping out kernel-looking addresses that came from userspace addresses. Which VM_SPLIT option are you running with, btw? I'm still pretty stumped, though.
* Dave Hansen <dave.hansen@linux.intel.com> wrote: > Did anyone else notice the > > [ 31.068198] ? vmalloc_sync_all+0x150/0x150 > > present in a bunch of the stack traces? That should be pretty uncommon. I thikn that's pretty unusual: > Is it just part of the normal do_page_fault() stack and the stack > dumper picks up on it? No, it should only be called by register_die_notifier(), which is not part of the regular stack dump, AFAICS. Thanks, Ingo
Linus Torvalds wrote: > On Mon, Jan 15, 2018 at 5:15 PM, Tetsuo Handa > <penguin-kernel@i-love.sakura.ne.jp> wrote: > > > > I can't reproduce this with CONFIG_FLATMEM=y . But I'm not sure whether > > we are hitting a bug in CONFIG_SPARSEMEM=y code, for the bug is highly > > timing dependent. > > Hmm. Maybe. But sparsemem really also generates *much* more complex > code particularly for the pfn_to_page() case. Since I got a faster reproducer, I tried full bisection between 4.11 and 4.12-rc1. But I have no idea why bisection arrives at c0332694903a37cf. ---------- gcc -Wall -O3 -m32 -o /mnt/a.out -x c - << "EOF" #include <stdlib.h> #include <unistd.h> int main(int argc, char *argv[]) { if (argc != 1) { unsigned long long size; char *buf = NULL; unsigned long long i; for (size = 1048576; size < 512ULL * (1 << 30); size += 1048576) { char *cp = realloc(buf, size); if (!cp) { size -= 1048576; break; } buf = cp; } for (i = 0; i < size; i += 4096) buf[i] = 0; _exit(0); } else while (1) { if (fork() == 0) { execlp(argv[0], argv[0], "", NULL); _exit(0); } sleep(1); } return 0; } EOF ---------- ---------- # bad: [2ea659a9ef488125eb46da6eb571de5eae5c43f6] Linux 4.12-rc1 # good: [a351e9b9fc24e982ec2f0e76379a49826036da12] Linux 4.11 git bisect start 'HEAD' 'v4.11' # good: [221656e7c4ce342b99c31eca96c1cbb6d1dce45f] Merge tag 'sound-4.12-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound git bisect good 221656e7c4ce342b99c31eca96c1cbb6d1dce45f # good: [c6a677c6f37bb7abc85ba7e3465e82b9f7eb1d91] Merge tag 'staging-4.12-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging git bisect good c6a677c6f37bb7abc85ba7e3465e82b9f7eb1d91 # bad: [0ff4c01b279a590a2826ade9321ad8c7ca5a1b6c] Merge tag 'armsoc-arm64' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc git bisect bad 0ff4c01b279a590a2826ade9321ad8c7ca5a1b6c # bad: [8f3207c7eab9d885cc64c778416537034a7d9c5b] Merge tag 'tty-4.12-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty git bisect bad 8f3207c7eab9d885cc64c778416537034a7d9c5b # bad: [9c6ee01ed5bb1ee489d580eaa60d7eb5a8ede336] Merge branch 'for-linus' of git://git.armlinux.org.uk/~rmk/linux-arm git bisect bad 9c6ee01ed5bb1ee489d580eaa60d7eb5a8ede336 # bad: [fe7a719b30dfdb4d55680461954b99b257ebe671] Merge branch 'for-next' of git://git.samba.org/sfrench/cifs-2.6 git bisect bad fe7a719b30dfdb4d55680461954b99b257ebe671 # good: [d557d1b58b3546bab2c5bc2d624c5709840e6b10] refcount: change EXPORT_SYMBOL markings git bisect good d557d1b58b3546bab2c5bc2d624c5709840e6b10 # good: [8f720d9f892e0e223dab8400f03130bc208c72e7] xfs: publish UUID in struct super_block git bisect good 8f720d9f892e0e223dab8400f03130bc208c72e7 # bad: [d173a25165c124442182f6b21d0c2ec381a0eebe] blk-mq: move debugfs declarations to a separate header file git bisect bad d173a25165c124442182f6b21d0c2ec381a0eebe # bad: [2719aa217e0d025dbfce74ac777815776ccec072] blk-mq: don't use sync workqueue flushing from drivers git bisect bad 2719aa217e0d025dbfce74ac777815776ccec072 # bad: [9f2779bff2f178496fb00b89797734ee245d2c93] blk-mq-sched: remove hack that bypasses scheduler for reserved requests git bisect bad 9f2779bff2f178496fb00b89797734ee245d2c93 # bad: [8afdd94c74e416de74a8ee61d79e4bf93466420b] mtip32xx: kill atomic argument to mtip_quiesce_io() git bisect bad 8afdd94c74e416de74a8ee61d79e4bf93466420b # bad: [0f6422a2c57c6afcf66ead903dc3fa6641184aa4] mtip32xx: get rid of 'atomic' argument to mtip_exec_internal_command() git bisect bad 0f6422a2c57c6afcf66ead903dc3fa6641184aa4 # bad: [c0332694903a37cf8ecdc9102d5c9e09cf8643d0] block: Remove elevator_change() git bisect bad c0332694903a37cf8ecdc9102d5c9e09cf8643d0 # first bad commit: [c0332694903a37cf8ecdc9102d5c9e09cf8643d0] block: Remove elevator_change() ---------- I tried different routes from mm/sparse.c , but I feel I can't find the culprit. ---------- # bad: [7660a6fddcbae344de8583aa4092071312f110c3] mm: allow slab_nomerge to be set at build time # good: [60a7a88dbb9fc9adcca78a10a3ecf36966b5a45c] mm/sparse: refine usemap_size() a little git bisect start '7660a6fddcbae344de8583aa4092071312f110c3' '60a7a88dbb9fc9adcca78a10a3ecf36966b5a45c' # bad: [9786e34e0a6055dbd1b46e16dfa791ac2b3da289] Merge tag 'for-linus-20170510' of git://git.infradead.org/linux-mtd git bisect bad 9786e34e0a6055dbd1b46e16dfa791ac2b3da289 # good: [1062ae4982cabbf60f89b4e069fbb7def7edc8f7] Merge tag 'drm-forgot-about-tegra-for-v4.12-rc1' of git://people.freedesktop.org/~airlied/linux git bisect good 1062ae4982cabbf60f89b4e069fbb7def7edc8f7 # bad: [bf5f89463f5b3109a72ed13ca62b57e90213387d] Merge branch 'akpm' (patches from Andrew) git bisect bad bf5f89463f5b3109a72ed13ca62b57e90213387d # good: [2b0d92b265324cfe42839a23cb46677bb0112c2c] staging: ks7010: remove cast from netdev_priv() git bisect good 2b0d92b265324cfe42839a23cb46677bb0112c2c # bad: [d484467c860dab3e17893d23b2238e1f581460fa] Merge tag 'xfs-4.12-merge-7' of git://git.kernel.org/pub/scm/fs/xfs/xfs-linux git bisect bad d484467c860dab3e17893d23b2238e1f581460fa # good: [e8357cdec3d1b6b42566ce3bc960e5e10c2b3787] [media] media: stk1160: Add Kconfig help on snd-usb-audio requirement git bisect good e8357cdec3d1b6b42566ce3bc960e5e10c2b3787 # good: [53ef7d0e208fa38c3f63d287e0c3ab174f1e1235] Merge tag 'libnvdimm-for-4.12' of git://git.kernel.org/pub/scm/linux/kernel/git/nvdimm/nvdimm git bisect good 53ef7d0e208fa38c3f63d287e0c3ab174f1e1235 # good: [044f1daaaaf7c86bc4fcf433848b7baae236946b] Merge branch 'for-linus' of git://git.kernel.dk/linux-block git bisect good 044f1daaaaf7c86bc4fcf433848b7baae236946b # good: [bf8eadbacb24e321c99bbdd901589942712810d1] xfs: remove xfs_bmap_remap_alloc git bisect good bf8eadbacb24e321c99bbdd901589942712810d1 # good: [e2a641922a3592b5ea226624d5abeb13eb49622c] xfs: corruption needs to respect endianess too! git bisect good e2a641922a3592b5ea226624d5abeb13eb49622c # good: [3c3781951c9a155a56e5eed567349118374cc315] xfs: Allow user to kill fstrim process git bisect good 3c3781951c9a155a56e5eed567349118374cc315 # good: [ae2c4ac2dd39b23a87ddb14ceddc3f2872c6aef5] xfs: update ag iterator to support wait on new inodes git bisect good ae2c4ac2dd39b23a87ddb14ceddc3f2872c6aef5 # good: [fe0be23e68200573de027de9b8cc2b27e7fce35e] xfs: reserve enough blocks to handle btree splits when remapping git bisect good fe0be23e68200573de027de9b8cc2b27e7fce35e # good: [161f55efba5ddccc690139fae9373cafc3447a97] xfs: fix use-after-free in xfs_finish_page_writeback git bisect good 161f55efba5ddccc690139fae9373cafc3447a97 # first bad commit: [d484467c860dab3e17893d23b2238e1f581460fa] Merge tag 'xfs-4.12-merge-7' of git://git.kernel.org/pub/scm/fs/xfs/xfs-linux # bad: [7660a6fddcbae344de8583aa4092071312f110c3] mm: allow slab_nomerge to be set at build time # good: [60a7a88dbb9fc9adcca78a10a3ecf36966b5a45c] mm/sparse: refine usemap_size() a little git bisect start 'HEAD' '60a7a88dbb9fc9adcca78a10a3ecf36966b5a45c' 'mm/' # bad: [499118e966f1d2150bd66647c8932343c4e9a0b8] mm: introduce memalloc_noreclaim_{save,restore} git bisect bad 499118e966f1d2150bd66647c8932343c4e9a0b8 # good: [5e82cd120382ad7bbcc82298e34a034538b4384c] kasan: introduce helper functions for determining bug type git bisect good 5e82cd120382ad7bbcc82298e34a034538b4384c # bad: [f25ba6dccc3bfe7e1524f4498a171be038507c45] mm, compaction: reorder fields in struct compact_control git bisect bad f25ba6dccc3bfe7e1524f4498a171be038507c45 # good: [b19385993623c1a18a686b6b271cd24d5aa96f52] kasan: separate report parts by empty lines git bisect good b19385993623c1a18a686b6b271cd24d5aa96f52 # good: [ab182e67ec99ea0c8d7435a32a4a1ed9bb02559a] Merge tag 'arm64-upstream' of git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux git bisect good ab182e67ec99ea0c8d7435a32a4a1ed9bb02559a # good: [e4231bcda72daef497af45e195a33daa0f9357d0] cma: Introduce cma_for_each_area git bisect good e4231bcda72daef497af45e195a33daa0f9357d0 # good: [c6a677c6f37bb7abc85ba7e3465e82b9f7eb1d91] Merge tag 'staging-4.12-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging git bisect good c6a677c6f37bb7abc85ba7e3465e82b9f7eb1d91 # first bad commit: [f25ba6dccc3bfe7e1524f4498a171be038507c45] mm, compaction: reorder fields in struct compact_control ---------- > > It also has much less testing. For example, on x86-64 we do use > sparsemem, but we use the VMEMMAP version of sparsemem: the version > that does *not* play really odd and complex games with that whole > pfn_to_page(). > > I've always felt like sparsemem was really damn complicated. The > whole "section_mem_map" encoding is really subtle and odd. > > And considering that we're getting what appears to be a invalid page, > in one of the more complicated sequences that very much does that > whole pfn_to_page(), I really wonder. > > I wonder if somebody could add some VM_BUG_ON() checks to the > non-vmemmap case of sparsemem in include/asm-generic/memory_model.h. > > Because this: > > #define __pfn_to_page(pfn) \ > ({ unsigned long __pfn = (pfn); \ > struct mem_section *__sec = __pfn_to_section(__pfn); \ > __section_mem_map_addr(__sec) + __pfn; \ > }) > > is really subtle, and if we have some case where we pass in an > out-of-range pfn, or some case where we get the section wrong (because > the pfn is between sections or whatever due to some subtle setup bug), > things will really go sideways. > > The reason I was hoping you could do this for FLATMEM is that it's > much easier to verify the pfn range in that case. The sparsemem cases > really makes it much nastier. > > That said, all of that code is really old. Most of it goes back to > -05/06 or so. But since you seem to be able to reproduce at least back > to 4.8, I guess this bug does back years too. I feel that the bug in 4.8 is a different one, though the reproducer is the same. > > But I'm adding Dave Hansen explicitly to the cc, in case he has any > ideas. Not because I blame him, but he's touched the sparsemem code > fairly recently, so maybe he'd have some idea on adding sanity > checking to the sparsemem version of pfn_to_page(). > > > I dont know why but selecting CONFIG_FLATMEM=y seems to avoid a different bug > > where bootup of qemu randomly fails at > > Hmm. That looks very different indeed. But if CONFIG_SPARSEMEM > (presumably together with HIGHMEM) has some odd off-by-one corner case > or similar, who knows *what* issues it could trigger. It turned out that CONFIG_FLATMEM was irrelevant. I just did not hit it.
On Tue, Jan 16, 2018 at 12:06 AM, Dave Hansen <dave.hansen@linux.intel.com> wrote: > On 01/15/2018 06:14 PM, Linus Torvalds wrote: >> But I'm adding Dave Hansen explicitly to the cc, in case he has any >> ideas. Not because I blame him, but he's touched the sparsemem code >> fairly recently, so maybe he'd have some idea on adding sanity >> checking to the sparsemem version of pfn_to_page(). > > I swear I haven't touched it lately! Heh. I did git blame -C mm/sparse.c | grep 2017 and your name shows up at the beginning a lot because of commit c4e1be9ec113 ("mm, sparsemem: break out of loops early"). And Michal Hocko (who shows up even more) was already on the cc. > I'm not sure I'd go after pfn_to_page(). *Maybe* if we were close to > the places where we've done a pfn_to_page(), but I'm not seeing those. Fair enough. I just wanted to add debugging, looked at Tetsuo's config, and went "no way am I adding debugging to the sparsemem case because it's so confusing". That said, I also started looking at "kmap_to_page()". That's something that is *really* different with HIGHMEM, and while most of the users are in random drivers that do crazy things, I do note that one of the users is in mm/swap.c. That thing goes back to commit 5a178119b0fb ("mm: add support for direct_IO to highmem pages") and was only used for swap_writepage(), if I read this right. That swap_writepage() use of kmap()'ed patches was removed some time later in commit 62a8067a7f35 ("bio_vec-backed iov_iter"), but the crazy kmap_to_page() thing remained. I see nothing actively wrong in there, but it really feels like a "that is all bogus" thing to me. > Did anyone else notice the > > [ 31.068198] ? vmalloc_sync_all+0x150/0x150 > > present in a bunch of the stack traces? That should be pretty uncommon. No, didn't notice that. And yes, vmalloc_sync_all() might be interesting. > Is it just part of the normal do_page_fault() stack and the stack > dumper picks up on it? I don't think so. It should *not* happen normally. The fact that it shows up in the trace means it happened that time. It doesn't seem HIGHMEM-related, though. Or maybe the highmem signal is bogus too, and it's just that Tetsuo's reproducer needs magical timing. Linus
On Tue, Jan 16, 2018 at 9:33 AM, Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp> wrote: > > Since I got a faster reproducer, I tried full bisection between 4.11 and 4.12-rc1. > But I have no idea why bisection arrives at c0332694903a37cf. I don't think your reproducer is 100% reliable. And bisection is great because it's very aggressive and optimal when it comes to testing. But that also implies that if *any* of the good/bad choices were incorrect, then the end result is pure garbage and isn't even *close* to the right commit. > It turned out that CONFIG_FLATMEM was irrelevant. I just did not hit it. So have you actually been able to see the problem with FLATMEM, or is this based on the bisect? Because I really think the bisect is pretty much guaranteed to be wrong. Linus
Linus Torvalds wrote: > > It turned out that CONFIG_FLATMEM was irrelevant. I just did not hit it. > > So have you actually been able to see the problem with FLATMEM, or is > this based on the bisect? Because I really think the bisect is pretty > much guaranteed to be wrong. Oops, this "it" is "a different bug where bootup of qemu randomly hangs at [ 0.001000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.003000] ..MP-BIOS bug: 8254 timer not connected to IO-APIC [ 0.003000] ...trying to set up timer (IRQ0) through the 8259A ... [ 0.003000] ..... (found apic 0 pin 2) ... [ 0.005000] ....... failed. [ 0.005000] ...trying to set up timer as Virtual Wire IRQ... [ 13.120000] random: crng init done ". This bug occurs with both CONFIG_FLATMEM=y or CONFIG_SPARSEMEM=y . > On Tue, Jan 16, 2018 at 9:33 AM, Tetsuo Handa > <penguin-kernel@i-love.sakura.ne.jp> wrote: > > > > Since I got a faster reproducer, I tried full bisection between 4.11 and 4.12-rc1. > > But I have no idea why bisection arrives at c0332694903a37cf. > > I don't think your reproducer is 100% reliable. > > And bisection is great because it's very aggressive and optimal when > it comes to testing. But that also implies that if *any* of the > good/bad choices were incorrect, then the end result is pure garbage > and isn't even *close* to the right commit. OK. I missed the mark. I overlooked that 4.11 already has this problem. ---------- [ 40.272926] BUG: unable to handle kernel paging request at f6d74b44 [ 40.272934] IP: page_remove_rmap+0x7/0x2c0 [ 40.272935] *pde = 3732c067 [ 40.272936] *pte = 36d74062 [ 40.272936] [ 40.272938] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC [ 40.272939] Modules linked in: xfs libcrc32c sr_mod cdrom sd_mod ata_generic pata_acpi serio_raw mptspi scsi_transport_spi mptscsih e1000 mptbase ata_piix libata [ 40.272952] CPU: 6 PID: 719 Comm: b.out Not tainted 4.11.0 #266 [ 40.272952] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 40.272953] task: ef4c1e40 task.stack: ef578000 [ 40.272955] EIP: page_remove_rmap+0x7/0x2c0 [ 40.272956] EFLAGS: 00010246 CPU: 6 [ 40.272957] EAX: f6d74b30 EBX: f6d74b30 ECX: 00000000 EDX: 00000000 [ 40.272958] ESI: ef7d9640 EDI: 00000093 EBP: ef579a78 ESP: ef579a70 [ 40.272959] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 40.272961] CR0: 80050033 CR2: f6d74b44 CR3: 2f4a8000 CR4: 000406d0 [ 40.273046] Call Trace: [ 40.273050] try_to_unmap_one+0x206/0x4f0 [ 40.273055] rmap_walk_file+0x13c/0x270 [ 40.273057] rmap_walk+0x32/0x60 [ 40.273058] try_to_unmap+0xad/0x150 [ 40.273060] ? page_remove_rmap+0x2c0/0x2c0 [ 40.273062] ? page_not_mapped+0x10/0x10 [ 40.273063] ? page_get_anon_vma+0x90/0x90 [ 40.273066] shrink_page_list+0x37a/0xd10 [ 40.273069] shrink_inactive_list+0x173/0x370 [ 40.273072] shrink_node_memcg+0x572/0x7d0 [ 40.273074] ? shrink_slab+0x1a0/0x2e0 [ 40.273077] shrink_node+0xb3/0x2c0 [ 40.273079] do_try_to_free_pages+0xb2/0x2b0 [ 40.273081] try_to_free_pages+0x1a4/0x2f0 [ 40.273085] ? schedule_timeout+0x142/0x200 [ 40.273088] __alloc_pages_slowpath+0x360/0x7e6 [ 40.273091] __alloc_pages_nodemask+0x1a4/0x1b0 [ 40.273093] do_anonymous_page+0xcb/0x500 [ 40.273120] ? xfs_filemap_fault+0x36/0x40 [xfs] [ 40.273122] handle_mm_fault+0x52f/0x990 [ 40.273125] __do_page_fault+0x19c/0x460 [ 40.273127] ? __do_page_fault+0x460/0x460 [ 40.273129] do_page_fault+0x1a/0x20 [ 40.273131] common_exception+0x6c/0x72 [ 40.273133] EIP: 0x8048437 [ 40.273133] EFLAGS: 00010202 CPU: 6 [ 40.273134] EAX: 001f8000 EBX: 7ff00000 ECX: 37803008 EDX: 00000000 [ 40.273135] ESI: 7ff00000 EDI: 00000000 EBP: bfeffa68 ESP: bfeffa30 [ 40.273137] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b [ 40.273137] Code: ff ff ba 78 50 7a c1 89 d8 e8 a6 f8 fe ff 0f 0b 83 e8 01 e9 66 ff ff ff 8d b6 00 00 00 00 8d bf 00 00 00 00 55 89 e5 56 53 89 c3 <8b> 40 14 a8 01 0f 85 a4 01 00 00 89 d8 f6 40 04 01 74 5e 84 d2 [ 40.273161] EIP: page_remove_rmap+0x7/0x2c0 SS:ESP: 0068:ef579a70 [ 40.273162] CR2: 00000000f6d74b44 [ 40.273164] ---[ end trace 902077077bed43fd ]--- ---------- I needed to bisect between 4.10 and 4.11, and I got plausible culprit. ---------- # bad: [a351e9b9fc24e982ec2f0e76379a49826036da12] Linux 4.11 # good: [c470abd4fde40ea6a0846a2beab642a578c0b8cd] Linux 4.10 # good: [69973b830859bc6529a7a0468ba0d80ee5117826] Linux 4.9 # good: [c8d2bc9bc39ebea8437fd974fdbc21847bb897a3] Linux 4.8 # good: [523d939ef98fd712632d93a5a2b588e477a7565e] Linux 4.7 # good: [2dcd0af568b0cf583645c8a317dd12e344b1c72a] Linux 4.6 # good: [b562e44f507e863c6792946e4e1b1449fbbac85d] Linux 4.5 # good: [afd2ff9b7e1b367172f18ba7f693dfb62bdcb2dc] Linux 4.4 # good: [6a13feb9c82803e2b815eca72fa7a9f5561d7861] Linux 4.3 # good: [64291f7db5bd8150a74ad2036f1037e6a0428df2] Linux 4.2 # good: [b953c0d234bc72e8489d3bf51a276c5c4ec85345] Linux 4.1 # good: [39a8804455fb23f09157341d3ba7db6d7ae6ee76] Linux 4.0 git bisect start 'v4.11' 'v4.10' 'v4.9' 'v4.8' 'v4.7' 'v4.6' 'v4.5' 'v4.4' 'v4.3' 'v4.2' 'v4.1' 'v4.0' 'mm/' # good: [1b096e5ae9f7181c770d59c6895f23a76c63adee] z3fold: extend compaction function git bisect good 1b096e5ae9f7181c770d59c6895f23a76c63adee # good: [8703e8a465b1e9cadc3680b4b1248f5987e54518] sched/headers: Prepare for new header dependencies before moving code to <linux/sched/user.h> git bisect good 8703e8a465b1e9cadc3680b4b1248f5987e54518 # bad: [8fe3ccaed080a7804bc459c42e0419253973be92] Merge branch 'akpm' (patches from Andrew) git bisect bad 8fe3ccaed080a7804bc459c42e0419253973be92 # good: [1827adb11ad26b2290dc9fe2aaf54976b2439865] Merge branch 'WIP.sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip git bisect good 1827adb11ad26b2290dc9fe2aaf54976b2439865 # bad: [8346242a7e32c4c93316684ad8f45473932586b9] rmap: fix NULL-pointer dereference on THP munlocking git bisect bad 8346242a7e32c4c93316684ad8f45473932586b9 # bad: [ce9311cf95ad8baf044a014738d76973d93b739a] mm/vmstats: add thp_split_pud event for clarity git bisect bad ce9311cf95ad8baf044a014738d76973d93b739a # good: [590dce2d4934fb909b112cd80c80486362337744] Merge branch 'rebased-statx' of git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs git bisect good 590dce2d4934fb909b112cd80c80486362337744 # bad: [b4fb8f66f1ae2e167d06c12d018025a8d4d3ba7e] mm, page_alloc: Add missing check for memory holes git bisect bad b4fb8f66f1ae2e167d06c12d018025a8d4d3ba7e # first bad commit: [b4fb8f66f1ae2e167d06c12d018025a8d4d3ba7e] mm, page_alloc: Add missing check for memory holes ---------- I haven't completed bisecting between b4fb8f66f1ae2e16 and c470abd4fde40ea6, but b4fb8f66f1ae2e16 ("mm, page_alloc: Add missing check for memory holes") and 13ad59df67f19788 ("mm, page_alloc: avoid page_to_pfn() when merging buddies") are talking about memory holes, which matches the situation that I'm trivially hitting the bug if CONFIG_SPARSEMEM=y . ---------- # bad: [b4fb8f66f1ae2e167d06c12d018025a8d4d3ba7e] mm, page_alloc: Add missing check for memory holes # good: [590dce2d4934fb909b112cd80c80486362337744] Merge branch 'rebased-statx' of git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs # good: [1827adb11ad26b2290dc9fe2aaf54976b2439865] Merge branch 'WIP.sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip # good: [8703e8a465b1e9cadc3680b4b1248f5987e54518] sched/headers: Prepare for new header dependencies before moving code to <linux/sched/user.h> # good: [1b096e5ae9f7181c770d59c6895f23a76c63adee] z3fold: extend compaction function # good: [c470abd4fde40ea6a0846a2beab642a578c0b8cd] Linux 4.10 # good: [69973b830859bc6529a7a0468ba0d80ee5117826] Linux 4.9 # good: [c8d2bc9bc39ebea8437fd974fdbc21847bb897a3] Linux 4.8 # good: [523d939ef98fd712632d93a5a2b588e477a7565e] Linux 4.7 # good: [2dcd0af568b0cf583645c8a317dd12e344b1c72a] Linux 4.6 # good: [b562e44f507e863c6792946e4e1b1449fbbac85d] Linux 4.5 # good: [afd2ff9b7e1b367172f18ba7f693dfb62bdcb2dc] Linux 4.4 # good: [6a13feb9c82803e2b815eca72fa7a9f5561d7861] Linux 4.3 # good: [64291f7db5bd8150a74ad2036f1037e6a0428df2] Linux 4.2 # good: [b953c0d234bc72e8489d3bf51a276c5c4ec85345] Linux 4.1 # good: [39a8804455fb23f09157341d3ba7db6d7ae6ee76] Linux 4.0 # bad: [8a9172356f747dc3734cc8043a44bbe158f44749] Merge branch 'timers-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip # bad: [04bb94b13c02e9dbc92d622cddf88937127bd7ed] overlayfs: remove now unnecessary header file include # bad: [bd0f9b356d00aa241ced36fb075a07041c28d3b8] sched/headers: fix up header file dependency on <linux/sched/signal.h> # bad: [ec3b93ae0bf4742e9cbb40e1964129926c1464e0] Merge branch 'x86-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip ---------- ---------- [ 30.997908] a.out invoked oom-killer: gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0 [ 31.002850] CPU: 0 PID: 274 Comm: a.out Not tainted 4.11.0-rc1-00068-g8a91723 #341 [ 31.005963] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 31.010320] Call Trace: [ 31.011391] dump_stack+0x58/0x73 [ 31.012774] dump_header+0x92/0x202 [ 31.014319] ? ___ratelimit+0x83/0xf0 [ 31.015854] oom_kill_process+0x1e5/0x3b0 [ 31.017682] ? has_capability_noaudit+0x1f/0x30 [ 31.019629] ? oom_badness+0xcf/0x130 [ 31.021182] ? oom_evaluate_task+0x14/0xe0 [ 31.022909] out_of_memory+0xe1/0x280 [ 31.024460] __alloc_pages_nodemask+0x70d/0x9d0 [ 31.026347] ? vma_gap_callbacks_rotate+0x14/0x20 [ 31.028292] handle_mm_fault+0x599/0xd90 [ 31.029926] __do_page_fault+0x197/0x450 [ 31.031480] ? __do_page_fault+0x450/0x450 [ 31.032999] do_page_fault+0x1a/0x20 [ 31.034639] common_exception+0x6c/0x72 [ 31.036266] EIP: 0x804858f [ 31.037430] EFLAGS: 00010202 CPU: 0 [ 31.038921] EAX: 007bc000 EBX: 376aa008 ECX: 37e66008 EDX: 00000000 [ 31.041530] ESI: 7ff00000 EDI: 00000000 EBP: bfcc7368 ESP: bfcc7330 [ 31.044118] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b [ 31.046387] Mem-Info: [ 31.047394] active_anon:656090 inactive_anon:0 isolated_anon:0 [ 31.047394] active_file:0 inactive_file:0 isolated_file:3 [ 31.047394] unevictable:0 dirty:0 writeback:0 unstable:0 [ 31.047394] slab_reclaimable:173 slab_unreclaimable:20805 [ 31.047394] mapped:4 shmem:0 pagetables:38151 bounce:0 [ 31.047394] free:31109 free_pcp:171 free_cma:0 [ 31.060114] Node 0 active_anon:2624360kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):12kB mapped:16kB dirty:0kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB pages_scanned:151 all_unreclaimable? yes [ 31.071561] DMA free:12720kB min:788kB low:984kB high:1180kB active_anon:3196kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15916kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 31.080790] BUG: unable to handle kernel paging request at bc25106a [ 31.080799] IP: page_remove_rmap+0x17/0x260 [ 31.080800] *pde = 00000000 [ 31.080801] [ 31.080803] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC [ 31.080804] Modules linked in: [ 31.080807] CPU: 1 PID: 61 Comm: kswapd0 Not tainted 4.11.0-rc1-00068-g8a91723 #341 [ 31.080808] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015 [ 31.080809] task: f517e300 task.stack: f5346000 [ 31.080812] EIP: page_remove_rmap+0x17/0x260 [ 31.080812] EFLAGS: 00010286 CPU: 1 [ 31.080814] EAX: bc251066 EBX: f3f2dbf0 ECX: 01de4080 EDX: 00000000 [ 31.080815] ESI: f3f2dbf0 EDI: f5970080 EBP: f5347c24 ESP: f5347c18 [ 31.080816] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 31.080817] CR0: 80050033 CR2: bc25106a CR3: 0170f000 CR4: 000406d0 [ 31.080897] Call Trace: [ 31.080902] try_to_unmap_one+0x210/0x4b0 [ 31.080905] rmap_walk_file+0xf0/0x200 [ 31.080907] rmap_walk+0x32/0x60 [ 31.080909] try_to_unmap+0x95/0x120 [ 31.080910] ? page_remove_rmap+0x260/0x260 [ 31.080912] ? page_not_mapped+0x10/0x10 [ 31.080914] ? page_get_anon_vma+0x90/0x90 [ 31.080916] shrink_page_list+0x387/0xbf0 [ 31.080919] shrink_inactive_list+0x173/0x370 [ 31.080921] shrink_node_memcg+0x572/0x7d0 [ 31.080924] ? __list_lru_count_one.isra.7+0x14/0x40 [ 31.080927] ? tick_program_event+0x3b/0x70 [ 31.080929] shrink_node+0xb3/0x2c0 [ 31.080931] kswapd+0x27f/0x5a0 [ 31.080935] kthread+0xd1/0x100 [ 31.080936] ? mem_cgroup_shrink_node+0xa0/0xa0 [ 31.080938] ? kthread_park+0x70/0x70 [ 31.080942] ret_from_fork+0x21/0x2c [ 31.080943] Code: 83 e8 01 90 e9 7a ff ff ff 83 e8 01 e9 60 ff ff ff 8d 76 00 55 89 e5 56 53 89 c3 83 ec 04 8b 40 14 a8 01 0f 85 00 02 00 00 89 d8 <f6> 40 04 01 74 6b 84 d2 0f 85 3b 01 00 00 f0 83 43 0c ff 78 0c [ 31.080981] EIP: page_remove_rmap+0x17/0x260 SS:ESP: 0068:f5347c18 [ 31.080981] CR2: 00000000bc25106a [ 31.080983] ---[ end trace 53061eeda268128d ]--- [ 31.159021] lowmem_reserve[]: 0 827 3011 3011 [ 31.160883] Normal free:111096kB min:42088kB low:52608kB high:63128kB active_anon:385820kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:892920kB managed:847288kB mlocked:0kB slab_reclaimable:692kB slab_unreclaimable:83220kB kernel_stack:74800kB pagetables:152604kB bounce:0kB free_pcp:680kB local_pcp:120kB free_cma:0kB [ 31.173443] lowmem_reserve[]: 0 0 17471 17471 [ 31.175185] HighMem free:620kB min:512kB low:28284kB high:56056kB active_anon:2233384kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:2236360kB managed:2236360kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 31.186860] lowmem_reserve[]: 0 0 0 0 [ 31.188445] DMA: 2*4kB (UM) 1*8kB (U) 0*16kB 1*32kB (U) 2*64kB (U) 2*128kB (UM) 2*256kB (UM) 1*512kB (M) 1*1024kB (U) 1*2048kB (U) 2*4096kB (M) = 12720kB [ 31.194038] Normal: 41*4kB (UME) 114*8kB (UME) 58*16kB (UE) 23*32kB (UME) 22*64kB (UME) 11*128kB (UME) 6*256kB (UM) 2*512kB (UE) 1*1024kB (U) 1*2048kB (E) 24*4096kB (M) = 109492kB [ 31.200324] HighMem: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 0kB [ 31.204414] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=4096kB [ 31.207586] 3 total pagecache pages [ 31.209085] 0 pages in swap cache [ 31.210527] Swap cache stats: add 0, delete 0, find 0/0 [ 31.212706] Free swap = 0kB [ 31.213952] Total swap = 0kB [ 31.215203] 786318 pages RAM [ 31.216439] 559090 pages HighMem/MovableOnly [ 31.218281] 11427 pages reserved [ 31.219486] 0 pages cma reserved [ 31.220862] Out of memory: Kill process 129 (a.out) score 5 or sacrifice child [ 31.223843] Killed process 180 (a.out) total-vm:2108kB, anon-rss:56kB, file-rss:0kB, shmem-rss:0kB [ 31.231024] oom_reaper: reaped process 180 (a.out), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB ---------- Thus, I call for an attention by speculative execution. ;-)
diff --git a/kernel/exit.c b/kernel/exit.c index 995453d..baa7cea 100644 --- a/kernel/exit.c +++ b/kernel/exit.c @@ -765,6 +765,7 @@ void __noreturn do_exit(long code) struct task_struct *tsk = current; int group_dead; + pr_info("exit(%s/%u): started do_exit()\n", tsk->comm, tsk->pid); profile_task_exit(tsk); kcov_task_exit(tsk); @@ -808,7 +809,9 @@ void __noreturn do_exit(long code) schedule(); } + pr_info("exit(%s/%u): started exit_signals()\n", tsk->comm, tsk->pid); exit_signals(tsk); /* sets PF_EXITING */ + pr_info("exit(%s/%u): ended exit_signals()\n", tsk->comm, tsk->pid); /* * Ensure that all new tsk->pi_lock acquisitions must observe * PF_EXITING. Serializes against futex.c:attach_to_pi_owner(). @@ -829,6 +832,7 @@ void __noreturn do_exit(long code) } /* sync mm's RSS info before statistics gathering */ + pr_info("exit(%s/%u): started sync_mm_rss()\n", tsk->comm, tsk->pid); if (tsk->mm) sync_mm_rss(tsk->mm); acct_update_integrals(tsk); @@ -849,8 +853,10 @@ void __noreturn do_exit(long code) tsk->exit_code = code; taskstats_exit(tsk, group_dead); + pr_info("exit(%s/%u): started exit_mm()\n", tsk->comm, tsk->pid); exit_mm(); - + pr_info("exit(%s/%u): ended exit_mm()\n", tsk->comm, tsk->pid); + if (group_dead) acct_process(); trace_sched_process_exit(tsk); @@ -919,6 +925,7 @@ void __noreturn do_exit(long code) exit_tasks_rcu_finish(); lockdep_free_task(tsk); + pr_info("exit(%s/%u): ended do_exit()\n", tsk->comm, tsk->pid); do_task_dead(); } EXPORT_SYMBOL_GPL(do_exit); diff --git a/mm/oom_kill.c b/mm/oom_kill.c index 29f8555..8bd3f25 100644 --- a/mm/oom_kill.c +++ b/mm/oom_kill.c @@ -505,6 +505,7 @@ static bool __oom_reap_task_mm(struct task_struct *tsk, struct mm_struct *mm) * # no TIF_MEMDIE task selects new victim * unmap_page_range # frees some memory */ + pr_info("oom_reaper: started reaping\n"); mutex_lock(&oom_lock); if (!down_read_trylock(&mm->mmap_sem)) {