Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1210270 > unrolled thread

Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and 4.2.0-rc7

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Vlastimil Babka <vbabka@suse.cz> - 2015-08-20 10:20 +0200
    Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Vlastimil Babka <vbabka@suse.cz> - 2015-08-21 13:40 +0200
      Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Vlastimil Babka <vbabka@suse.cz> - 2015-08-21 13:50 +0200
        Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Arthur Marsh <arthur.marsh@internode.on.net> - 2015-08-21 14:50 +0200
        Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Arthur Marsh <arthur.marsh@internode.on.net> - 2015-08-22 06:50 +0200
          Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Vlastimil Babka <vbabka@suse.cz> - 2015-08-22 09:10 +0200
      Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and  4.2.0-rc7 Arthur Marsh <arthur.marsh@internode.on.net> - 2015-08-21 14:40 +0200

#1210270 — Re: difficult to pinpoint exhaustion of swap between 4.2.0-rc6 and 4.2.0-rc7

On 08/19/2015 05:44 PM, Arthur Marsh wrote:
> Hi, I've found that the Linus' git head kernel has had some unwelcome
> behaviour where chromium browser would exhaust all swap space in the
> course of a few hours. The behaviour appeared before the release of
> 4.2.0-rc7.

Do you have any more details about the memory/swap usage? Is it really 
that chromium process(es) itself eats more memory and starts swapping, 
or that something else (a graphics driver?) eats kernel memory, and 
chromium as one of the biggest processes is driven to swap by that? Can 
you provide e.g. top output with good/bad kernels?

Also what does /proc/meminfo and /proc/zoneinfo look like when it's 
swapping?

To see which processes use swap, you can try [1] :
for file in /proc/*/status ; do awk '/VmSwap|Name/{printf $2 " " $3}END{ 
print ""}' $file; done | sort -k 2 -n -r | less

Thanks

[1] http://www.cyberciti.biz/faq/linux-which-process-is-using-swap/

> This does not happen with kernel 4.2.0-rc6.
>
> When I tried a git-bisect, the results where not conclusive due to the
> problem taking over an hour to appear after booting, the closest I came
> was around this commit (the actual problem may be a few commits either
> side):
>
> git bisect good
> 4f258a46346c03fa0bbb6199ffaf4e1f9f599660 is the first bad commit
> commit 4f258a46346c03fa0bbb6199ffaf4e1f9f599660
> Author: Martin K. Petersen <martin.petersen@oracle.com>
> Date:   Tue Jun 23 12:13:59 2015 -0400
>
>       sd: Fix maximum I/O size for BLOCK_PC requests
>
>       Commit bcdb247c6b6a ("sd: Limit transfer length") clamped the maximum
>       size of an I/O request to the MAXIMUM TRANSFER LENGTH field in the
> BLOCK
>       LIMITS VPD. This had the unfortunate effect of also limiting the
> maximum
>       size of non-filesystem requests sent to the device through sg/bsg.
>
>       Avoid using blk_queue_max_hw_sectors() and set the max_sectors queue
>       limit directly.
>
>       Also update the comment in blk_limits_max_hw_sectors() to clarify that
>       max_hw_sectors defines the limit for the I/O controller only.
>
>       Signed-off-by: Martin K. Petersen <martin.petersen@oracle.com>
>       Reported-by: Brian King <brking@linux.vnet.ibm.com>
>       Tested-by: Brian King <brking@linux.vnet.ibm.com>
>       Cc: stable@vger.kernel.org # 3.17+
>       Signed-off-by: James Bottomley <JBottomley@Odin.com>
>
> :040000 040000 fbd0519d9ee0a8f92a7dab9a9c6d7b7868974fba
> b4cf554c568813704993538008aed5b704624679 M      block
> :040000 040000 f2630c903cd36ede2619d173f9d1ea0d725ea111
> ff6b6f732afbf6f4b6b26a827c463de50f0e356c M      drivers
>
> Has anyone seen a similar problem?
> I can supply .config and other information if requested.
>
> Arthur.
>
> --
> To unsubscribe, send a message with 'unsubscribe linux-mm' in
> the body to majordomo@kvack.org.  For more info on Linux MM,
> see: http://www.linux-mm.org/ .
> Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>
>

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [next] | [standalone]

#1211120

On 08/21/2015 11:17 AM, Arthur Marsh wrote:
>
>
> Vlastimil Babka wrote on 20/08/15 17:46:
>> On 08/19/2015 05:44 PM, Arthur Marsh wrote:
>>> Hi, I've found that the Linus' git head kernel has had some unwelcome
>>> behaviour where chromium browser would exhaust all swap space in the
>>> course of a few hours. The behaviour appeared before the release of
>>> 4.2.0-rc7.
>>
>> Do you have any more details about the memory/swap usage? Is it really
>> that chromium process(es) itself eats more memory and starts swapping,
>> or that something else (a graphics driver?) eats kernel memory, and
>> chromium as one of the biggest processes is driven to swap by that? Can
>> you provide e.g. top output with good/bad kernels?
>>
>> Also what does /proc/meminfo and /proc/zoneinfo look like when it's
>> swapping?
>>
>> To see which processes use swap, you can try [1] :
>> for file in /proc/*/status ; do awk '/VmSwap|Name/{printf $2 " " $3}END{
>> print ""}' $file; done | sort -k 2 -n -r | less
>>
>> Thanks
>>
>> [1] http://www.cyberciti.biz/faq/linux-which-process-is-using-swap/
>>
>>> This does not happen with kernel 4.2.0-rc6.
>
> Sorry for the delay in replying. I had to give an extended run under
> kernel 4.2.0-rc6 to obtain comparative results. Both kernels' config
> files are attached.
>
> The applications running are the same both times, mainly iceweasel
> 38.1.0esr-3 and chromium 44.0.2403.107-1.
>
> With the rc7+ kernel but not the rc6 kernel, chromium eventually gets
> into a state of consuming lots of swap.
>
> I was able to capture the output requested when running a 4.2.0-rc7+
> kernel (Linus' git head as of around 05:00 UTC 19 August 2015) just
> before swap was exhausted, forcing me to do a control-alt-delete
> shutdown and waiting ages. The kernel config for the rc7+ is attached
>
> The comparison good kernel is from Debian:
> Linux am64 4.2.0-rc6-amd64 #1 SMP Debian 4.2~rc6-1~exp1 (2015-08-12)
> x86_64 GNU/Linux

Hm I didn't how similar are the configs, was the debian one used as a 
base for the self-compiled one? Just to rule out config differences... 
during the bisection you did use the same for compiling a "good" rc6 
kernel and "bad" rc7 kernel, right?

That, said, looking at the memory values:

rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
rc7: ...                                   = 4714MB

That's 2GB unaccounted for. Which is bad, and yet not enough to explain 
a full 4GB swap. Another noticeable difference is rc7 using 1560MB ShMem 
vs 476MB. The rest must be due to more anonymous memory used by the 
processes. Iceweasel looks unchanged, so I'm guessing the chromiums... 
the top output probably doesn't give us the whole picture here. I'm 
still suspecting a graphics driver, which one do you use?

The shmem could be inspected by listing ipcs -m and ipcs -mp and grep 
grep SYSV /proc/*/maps and figuring out what processes are behind the 
pids. Doing that for rc6 and rc7 could tell us which processes use the 
extra 1GB of shmem in rc7.


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1211122

On 08/21/2015 01:37 PM, Vlastimil Babka wrote:
>
> That, said, looking at the memory values:
>
> rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
> rc7: ...                                   = 4714MB
>
> That's 2GB unaccounted for.

So one brute-force way to see who allocated those 2GB is to use the 
page_owner debug feature. You need to enable CONFIG_PAGE_OWNER and then 
follow the Usage part of Documentation/vm/page_owner.txt
If you can do that, please send the sorted_page_owner.txt for rc7 when 
it's semi-nearing the exhausted swap. Then you could start doing a 
comparison run with rc6, but maybe it will be easy to figure from the 
rc7 log already. Thanks.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1211140

Vlastimil Babka wrote on 21/08/15 21:18:
> On 08/21/2015 01:37 PM, Vlastimil Babka wrote:
>>
>> That, said, looking at the memory values:
>>
>> rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
>> rc7: ...                                   = 4714MB
>>
>> That's 2GB unaccounted for.
>
> So one brute-force way to see who allocated those 2GB is to use the
> page_owner debug feature. You need to enable CONFIG_PAGE_OWNER and then
> follow the Usage part of Documentation/vm/page_owner.txt
> If you can do that, please send the sorted_page_owner.txt for rc7 when
> it's semi-nearing the exhausted swap. Then you could start doing a
> comparison run with rc6, but maybe it will be easy to figure from the
> rc7 log already. Thanks.
>

I'm currently rebuilding the rc7 kernel with CONFIG_PAGE_OWNER=y and 
will test that.

Arthur.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1211400

Vlastimil Babka wrote on 21/08/15 21:18:
> On 08/21/2015 01:37 PM, Vlastimil Babka wrote:
>>
>> That, said, looking at the memory values:
>>
>> rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
>> rc7: ...                                   = 4714MB
>>
>> That's 2GB unaccounted for.
>
> So one brute-force way to see who allocated those 2GB is to use the
> page_owner debug feature. You need to enable CONFIG_PAGE_OWNER and then
> follow the Usage part of Documentation/vm/page_owner.txt
> If you can do that, please send the sorted_page_owner.txt for rc7 when
> it's semi-nearing the exhausted swap. Then you could start doing a
> comparison run with rc6, but maybe it will be easy to figure from the
> rc7 log already. Thanks.
>

Documentation/vm/page_owner.txt does not mention the need to do:

mount -t debugfs none /sys/kernel/debug

Having done that when about 1.5 GiB swap was in use, the output of 
sorted_page_owner.txt with the rc7+ kernel starts with:

699487 times:
Page allocated via order 0, mask 0x280da
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff8118d35b>] handle_mm_fault+0x11bb/0x1480
  [<ffffffff8104c3e8>] __do_page_fault+0x178/0x480
  [<ffffffff8104c71b>] do_page_fault+0x2b/0x40
  [<ffffffff815b01a8>] page_fault+0x28/0x30
  [<ffffffffffffffff>] 0xffffffffffffffff

457823 times:
Page allocated via order 0, mask 0x202d0
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff8100a844>] dma_generic_alloc_coherent+0xa4/0xf0
  [<ffffffff810481fd>] x86_swiotlb_alloc_coherent+0x2d/0x60
  [<ffffffff8100a5ae>] dma_alloc_attrs+0x4e/0x90
  [<ffffffffa0427d72>] ttm_dma_populate+0x502/0x900 [ttm]
  [<ffffffffa046bf26>] radeon_ttm_tt_populate+0x216/0x2b0 [radeon]
  [<ffffffffa041dd74>] ttm_tt_bind+0x44/0x80 [ttm]
  [<ffffffffa0420316>] ttm_bo_handle_move_mem+0x3b6/0x440 [ttm]

213933 times:
Page allocated via order 0, mask 0x10200da
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff81158b7c>] pagecache_get_page+0x9c/0x1f0
  [<ffffffff81158cf7>] grab_cache_page_write_begin+0x27/0x40
  [<ffffffffa01228cd>] ext4_write_begin+0xbd/0x580 [ext4]
  [<ffffffff8115773a>] generic_perform_write+0xaa/0x1a0
  [<ffffffff8115a063>] __generic_file_write_iter+0x193/0x1f0
  [<ffffffffa0115c85>] ext4_file_write_iter+0xf5/0x490 [ext4]
  [<ffffffff811c6cf5>] __vfs_write+0xa5/0xe0

120198 times:
Page allocated via order 0, mask 0x200da
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff81175ab1>] shmem_getpage_gfp+0x381/0xa30
  [<ffffffff811767f2>] shmem_fault+0x62/0x1b0
  [<ffffffff81189648>] __do_fault+0x38/0x80
  [<ffffffff8118c4ac>] handle_mm_fault+0x30c/0x1480
  [<ffffffff8104c3e8>] __do_page_fault+0x178/0x480
  [<ffffffff8104c71b>] do_page_fault+0x2b/0x40
  [<ffffffff815b01a8>] page_fault+0x28/0x30

82253 times:
Page allocated via order 0, mask 0x213da
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff81167b41>] __do_page_cache_readahead+0x101/0x320
  [<ffffffff8115a778>] filemap_fault+0x388/0x400
  [<ffffffff81189648>] __do_fault+0x38/0x80
  [<ffffffff8118ce7f>] handle_mm_fault+0xcdf/0x1480
  [<ffffffff8104c3e8>] __do_page_fault+0x178/0x480
  [<ffffffff8104c71b>] do_page_fault+0x2b/0x40
  [<ffffffff815b01a8>] page_fault+0x28/0x30

47542 times:
Page allocated via order 0, mask 0x200da
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff81189baa>] wp_page_copy.isra.62+0x7a/0x5c0
  [<ffffffff8118b6fd>] do_wp_page+0xbd/0x600
  [<ffffffff8118c92c>] handle_mm_fault+0x78c/0x1480
  [<ffffffff8104c3e8>] __do_page_fault+0x178/0x480
  [<ffffffff8104c71b>] do_page_fault+0x2b/0x40
  [<ffffffff815b01a8>] page_fault+0x28/0x30
  [<ffffffffffffffff>] 0xffffffffffffffff

43843 times:
Page allocated via order 0, mask 0x0
  [<ffffffff81b0a34a>] page_ext_init+0xe5/0xea
  [<ffffffff81ae4ebe>] start_kernel+0x392/0x459
  [<ffffffff81ae4315>] x86_64_start_reservations+0x2a/0x2c
  [<ffffffff81ae444e>] x86_64_start_kernel+0x137/0x146
  [<ffffffffffffffff>] 0xffffffffffffffff

28075 times:
Page allocated via order 0, mask 0x8
  [<ffffffff81160388>] split_free_page+0x38/0x50
  [<ffffffff81183865>] isolate_freepages_block+0x205/0x4b0
  [<ffffffff81183cb1>] compaction_alloc+0x1a1/0x280
  [<ffffffff811b2a51>] migrate_pages+0x241/0x9a0
  [<ffffffff8118553e>] compact_zone+0x55e/0xea0
  [<ffffffff81185ed8>] compact_zone_order+0x58/0x70
  [<ffffffff81186317>] try_to_compact_pages+0x127/0x5b0
  [<ffffffff811611f9>] __alloc_pages_direct_compact+0x49/0xf0

19845 times:
Page allocated via order 0, mask 0x2a4050
  [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
  [<ffffffff811ad53b>] cache_alloc_refill+0x33b/0x5b0
  [<ffffffff811ad095>] kmem_cache_alloc+0x1a5/0x310
  [<ffffffffa0132dca>] ext4_alloc_inode+0x1a/0x210 [ext4]
  [<ffffffff811e3f88>] alloc_inode+0x18/0x90
  [<ffffffff811e58a8>] iget_locked+0xd8/0x190
  [<ffffffffa011e85c>] ext4_iget+0x3c/0xa70 [ext4]
  [<ffffffffa011f2bb>] ext4_iget_normal+0x2b/0x40 [ext4]

Also, once when attempting to do:

cat /sys/kernel/debug/page_owner > page_owner_full.txt

I received the following error:


[18410.829060] cat: page allocation failure: order:5, mode:0x2040d0
[18410.829068] CPU: 3 PID: 1732 Comm: cat Not tainted 4.2.0-rc7+ #1907
[18410.829070] Hardware name: System manufacturer System Product 
Name/M3A78 PRO, BIOS 1701    01/27/2011
[18410.829073]  0000000000000005 ffff88001f4d7a58 ffffffff815a554d 
0000000000000034
[18410.829078]  00000000002040d0 ffff88001f4d7ae8 ffffffff8115dedc 
ffff8800360b4540
[18410.829082]  0000000000000005 ffff8800360b4540 00000000002040d0 
ffff88001f4d7bc0
[18410.829085] Call Trace:
[18410.829091]  [<ffffffff815a554d>] dump_stack+0x4f/0x7b
[18410.829096]  [<ffffffff8115dedc>] warn_alloc_failed+0xdc/0x130
[18410.829099]  [<ffffffff81161298>] ? 
__alloc_pages_direct_compact+0xe8/0xf0
[18410.829101]  [<ffffffff81161b31>] __alloc_pages_nodemask+0x891/0xb00
[18410.829104]  [<ffffffff810aa375>] ? __lock_acquire+0xc05/0x1c70
[18410.829107]  [<ffffffff811ad53b>] cache_alloc_refill+0x33b/0x5b0
[18410.829110]  [<ffffffff811c1764>] ? print_page_owner+0x54/0x350
[18410.829112]  [<ffffffff811adc7e>] __kmalloc+0x1be/0x330
[18410.829114]  [<ffffffff811c1764>] print_page_owner+0x54/0x350
[18410.829116]  [<ffffffff8115f786>] ? drain_pages_zone+0x76/0xa0
[18410.829118]  [<ffffffff8115f860>] ? page_alloc_cpu_notify+0x50/0x50
[18410.829119]  [<ffffffff8115f7cf>] ? drain_pages+0x1f/0x60
[18410.829122]  [<ffffffff810a93c6>] ? trace_hardirqs_on_caller+0x136/0x1c0
[18410.829123]  [<ffffffff8115f860>] ? page_alloc_cpu_notify+0x50/0x50
[18410.829126]  [<ffffffff81084403>] ? preempt_count_sub+0x23/0x60
[18410.829129]  [<ffffffff810eb58f>] ? on_each_cpu_mask+0x5f/0xd0
[18410.829131]  [<ffffffff811c1bbf>] read_page_owner+0x15f/0x180
[18410.829134]  [<ffffffff811c6ba3>] __vfs_read+0x23/0xd0
[18410.829137]  [<ffffffff8126581b>] ? security_file_permission+0x9b/0xc0
[18410.829139]  [<ffffffff811c71ba>] ? rw_verify_area+0x4a/0xe0
[18410.829141]  [<ffffffff811c72dd>] vfs_read+0x8d/0x140
[18410.829143]  [<ffffffff810acc51>] ? lockdep_sys_exit+0x1/0x90
[18410.829146]  [<ffffffff811c7cbd>] SyS_read+0x4d/0xb0
[18410.829149]  [<ffffffff815ae26e>] entry_SYSCALL_64_fastpath+0x12/0x76
[18410.829151] Mem-Info:
[18410.829157] active_anon:715055 inactive_anon:205953 isolated_anon:15
                 active_file:215967 inactive_file:199708 isolated_file:0
                 unevictable:5132 dirty:4186 writeback:5030 unstable:0
                 slab_reclaimable:49019 slab_unreclaimable:28035
                 mapped:168002 shmem:124895 pagetables:20296 bounce:0
                 free:14378 free_pcp:127 free_cma:0
[18410.829164] DMA free:15872kB min:20kB low:24kB high:28kB 
active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB 
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB 
managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB 
slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB 
pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB 
free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[18410.829166] lowmem_reserve[]: 0 2966 7692 7692
[18410.829174] DMA32 free:28064kB min:4296kB low:5368kB high:6444kB 
active_anon:1064284kB inactive_anon:359240kB active_file:348344kB 
inactive_file:326552kB unevictable:9228kB isolated(anon):60kB 
isolated(file):0kB present:3129024kB managed:3040444kB mlocked:9228kB 
dirty:6408kB writeback:7312kB mapped:276504kB shmem:197144kB 
slab_reclaimable:78148kB slab_unreclaimable:44692kB kernel_stack:5216kB 
pagetables:33052kB unstable:0kB bounce:0kB free_pcp:24kB local_pcp:20kB 
free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[18410.829176] lowmem_reserve[]: 0 0 4725 4725
[18410.829183] Normal free:13576kB min:6844kB low:8552kB high:10264kB 
active_anon:1795936kB inactive_anon:464572kB active_file:515524kB 
inactive_file:472280kB unevictable:11300kB isolated(anon):0kB 
isolated(file):0kB present:4980736kB managed:4839416kB mlocked:11300kB 
dirty:10336kB writeback:12808kB mapped:395504kB shmem:302436kB 
slab_reclaimable:117928kB slab_unreclaimable:67448kB kernel_stack:7392kB 
pagetables:48132kB unstable:0kB bounce:0kB free_pcp:484kB local_pcp:0kB 
free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[18410.829184] lowmem_reserve[]: 0 0 0 0
[18410.829188] DMA: 0*4kB 0*8kB 0*16kB 2*32kB (U) 1*64kB (U) 1*128kB (U) 
1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (EM) = 15872kB
[18410.829201] DMA32: 1914*4kB (UEM) 835*8kB (UEM) 390*16kB (UEM) 
170*32kB (EM) 34*64kB (M) 1*128kB (M) 0*256kB 0*512kB 0*1024kB 0*2048kB 
0*4096kB = 28320kB
[18410.829213] Normal: 1049*4kB (UEM) 511*8kB (UEM) 222*16kB (UEM) 
48*32kB (UM) 6*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 
0*4096kB = 13756kB
[18410.829225] Node 0 hugepages_total=0 hugepages_free=0 
hugepages_surp=0 hugepages_size=2048kB
[18410.829226] 555867 total pagecache pages
[18410.829228] 10431 pages in swap cache
[18410.829229] Swap cache stats: add 395263, delete 384832, find 34692/49351
[18410.829231] Free swap  = 2820524kB
[18410.829232] Total swap = 4194288kB
[18410.829275] 2031438 pages RAM
[18410.829276] 0 pages HighMem/MovableOnly
[18410.829277] 57497 pages reserved

I'll try to repeat the process with the 4.2.0-rc6 kernel also.

Arthur.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1211415

On 22.8.2015 6:48, Arthur Marsh wrote:
> 
> 
> Vlastimil Babka wrote on 21/08/15 21:18:
>> On 08/21/2015 01:37 PM, Vlastimil Babka wrote:
>>>
>>> That, said, looking at the memory values:
>>>
>>> rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
>>> rc7: ...                                   = 4714MB
>>>
>>> That's 2GB unaccounted for.
>>
>> So one brute-force way to see who allocated those 2GB is to use the
>> page_owner debug feature. You need to enable CONFIG_PAGE_OWNER and then
>> follow the Usage part of Documentation/vm/page_owner.txt
>> If you can do that, please send the sorted_page_owner.txt for rc7 when
>> it's semi-nearing the exhausted swap. Then you could start doing a
>> comparison run with rc6, but maybe it will be easy to figure from the
>> rc7 log already. Thanks.
>>
> 
> Documentation/vm/page_owner.txt does not mention the need to do:
> 
> mount -t debugfs none /sys/kernel/debug

Ah, right...

> Having done that when about 1.5 GiB swap was in use, the output of 
> sorted_page_owner.txt with the rc7+ kernel starts with:
> 
> 699487 times:
> Page allocated via order 0, mask 0x280da
>   [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
>   [<ffffffff8118d35b>] handle_mm_fault+0x11bb/0x1480
>   [<ffffffff8104c3e8>] __do_page_fault+0x178/0x480
>   [<ffffffff8104c71b>] do_page_fault+0x2b/0x40
>   [<ffffffff815b01a8>] page_fault+0x28/0x30
>   [<ffffffffffffffff>] 0xffffffffffffffff

That's userspace, that's fine.

> 457823 times:
> Page allocated via order 0, mask 0x202d0
>   [<ffffffff8116147e>] __alloc_pages_nodemask+0x1de/0xb00
>   [<ffffffff8100a844>] dma_generic_alloc_coherent+0xa4/0xf0
>   [<ffffffff810481fd>] x86_swiotlb_alloc_coherent+0x2d/0x60
>   [<ffffffff8100a5ae>] dma_alloc_attrs+0x4e/0x90
>   [<ffffffffa0427d72>] ttm_dma_populate+0x502/0x900 [ttm]
>   [<ffffffffa046bf26>] radeon_ttm_tt_populate+0x216/0x2b0 [radeon]
>   [<ffffffffa041dd74>] ttm_tt_bind+0x44/0x80 [ttm]
>   [<ffffffffa0420316>] ttm_bo_handle_move_mem+0x3b6/0x440 [ttm]

There. 1800MB of present RAM was allocated through ttm/radeon in rc7(+). And
apparently that doesn't happen with rc6.
The problem is, there were no commits between rc6 and rc7 in
drivers/gpu/drm/radeon/ or drivers/gpu/drm/ttm/. I'm CC'ing dri and some radeon
devs anyway. Please find the rest of this thread on lkml.

[...]

> 
> Also, once when attempting to do:
> 
> cat /sys/kernel/debug/page_owner > page_owner_full.txt
> 
> I received the following error:
> 
> 
> [18410.829060] cat: page allocation failure: order:5, mode:0x2040d0
> [18410.829068] CPU: 3 PID: 1732 Comm: cat Not tainted 4.2.0-rc7+ #1907
> [18410.829070] Hardware name: System manufacturer System Product 
> Name/M3A78 PRO, BIOS 1701    01/27/2011
> [18410.829073]  0000000000000005 ffff88001f4d7a58 ffffffff815a554d 
> 0000000000000034
> [18410.829078]  00000000002040d0 ffff88001f4d7ae8 ffffffff8115dedc 
> ffff8800360b4540
> [18410.829082]  0000000000000005 ffff8800360b4540 00000000002040d0 
> ffff88001f4d7bc0
> [18410.829085] Call Trace:
> [18410.829091]  [<ffffffff815a554d>] dump_stack+0x4f/0x7b
> [18410.829096]  [<ffffffff8115dedc>] warn_alloc_failed+0xdc/0x130
> [18410.829099]  [<ffffffff81161298>] ? 
> __alloc_pages_direct_compact+0xe8/0xf0
> [18410.829101]  [<ffffffff81161b31>] __alloc_pages_nodemask+0x891/0xb00
> [18410.829104]  [<ffffffff810aa375>] ? __lock_acquire+0xc05/0x1c70
> [18410.829107]  [<ffffffff811ad53b>] cache_alloc_refill+0x33b/0x5b0
> [18410.829110]  [<ffffffff811c1764>] ? print_page_owner+0x54/0x350
> [18410.829112]  [<ffffffff811adc7e>] __kmalloc+0x1be/0x330
> [18410.829114]  [<ffffffff811c1764>] print_page_owner+0x54/0x350
> [18410.829116]  [<ffffffff8115f786>] ? drain_pages_zone+0x76/0xa0
> [18410.829118]  [<ffffffff8115f860>] ? page_alloc_cpu_notify+0x50/0x50
> [18410.829119]  [<ffffffff8115f7cf>] ? drain_pages+0x1f/0x60
> [18410.829122]  [<ffffffff810a93c6>] ? trace_hardirqs_on_caller+0x136/0x1c0
> [18410.829123]  [<ffffffff8115f860>] ? page_alloc_cpu_notify+0x50/0x50
> [18410.829126]  [<ffffffff81084403>] ? preempt_count_sub+0x23/0x60
> [18410.829129]  [<ffffffff810eb58f>] ? on_each_cpu_mask+0x5f/0xd0
> [18410.829131]  [<ffffffff811c1bbf>] read_page_owner+0x15f/0x180
> [18410.829134]  [<ffffffff811c6ba3>] __vfs_read+0x23/0xd0
> [18410.829137]  [<ffffffff8126581b>] ? security_file_permission+0x9b/0xc0
> [18410.829139]  [<ffffffff811c71ba>] ? rw_verify_area+0x4a/0xe0
> [18410.829141]  [<ffffffff811c72dd>] vfs_read+0x8d/0x140
> [18410.829143]  [<ffffffff810acc51>] ? lockdep_sys_exit+0x1/0x90
> [18410.829146]  [<ffffffff811c7cbd>] SyS_read+0x4d/0xb0
> [18410.829149]  [<ffffffff815ae26e>] entry_SYSCALL_64_fastpath+0x12/0x76
> [18410.829151] Mem-Info:
> [18410.829157] active_anon:715055 inactive_anon:205953 isolated_anon:15
>                  active_file:215967 inactive_file:199708 isolated_file:0
>                  unevictable:5132 dirty:4186 writeback:5030 unstable:0
>                  slab_reclaimable:49019 slab_unreclaimable:28035
>                  mapped:168002 shmem:124895 pagetables:20296 bounce:0
>                  free:14378 free_pcp:127 free_cma:0
> [18410.829164] DMA free:15872kB min:20kB low:24kB high:28kB 
> active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB 
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB 
> managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB 
> slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB 
> pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB 
> free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
> [18410.829166] lowmem_reserve[]: 0 2966 7692 7692
> [18410.829174] DMA32 free:28064kB min:4296kB low:5368kB high:6444kB 
> active_anon:1064284kB inactive_anon:359240kB active_file:348344kB 
> inactive_file:326552kB unevictable:9228kB isolated(anon):60kB 
> isolated(file):0kB present:3129024kB managed:3040444kB mlocked:9228kB 
> dirty:6408kB writeback:7312kB mapped:276504kB shmem:197144kB 
> slab_reclaimable:78148kB slab_unreclaimable:44692kB kernel_stack:5216kB 
> pagetables:33052kB unstable:0kB bounce:0kB free_pcp:24kB local_pcp:20kB 
> free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> [18410.829176] lowmem_reserve[]: 0 0 4725 4725
> [18410.829183] Normal free:13576kB min:6844kB low:8552kB high:10264kB 
> active_anon:1795936kB inactive_anon:464572kB active_file:515524kB 
> inactive_file:472280kB unevictable:11300kB isolated(anon):0kB 
> isolated(file):0kB present:4980736kB managed:4839416kB mlocked:11300kB 
> dirty:10336kB writeback:12808kB mapped:395504kB shmem:302436kB 
> slab_reclaimable:117928kB slab_unreclaimable:67448kB kernel_stack:7392kB 
> pagetables:48132kB unstable:0kB bounce:0kB free_pcp:484kB local_pcp:0kB 
> free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> [18410.829184] lowmem_reserve[]: 0 0 0 0
> [18410.829188] DMA: 0*4kB 0*8kB 0*16kB 2*32kB (U) 1*64kB (U) 1*128kB (U) 
> 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (EM) = 15872kB
> [18410.829201] DMA32: 1914*4kB (UEM) 835*8kB (UEM) 390*16kB (UEM) 
> 170*32kB (EM) 34*64kB (M) 1*128kB (M) 0*256kB 0*512kB 0*1024kB 0*2048kB 
> 0*4096kB = 28320kB
> [18410.829213] Normal: 1049*4kB (UEM) 511*8kB (UEM) 222*16kB (UEM) 
> 48*32kB (UM) 6*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 
> 0*4096kB = 13756kB
> [18410.829225] Node 0 hugepages_total=0 hugepages_free=0 
> hugepages_surp=0 hugepages_size=2048kB
> [18410.829226] 555867 total pagecache pages
> [18410.829228] 10431 pages in swap cache
> [18410.829229] Swap cache stats: add 395263, delete 384832, find 34692/49351
> [18410.829231] Free swap  = 2820524kB
> [18410.829232] Total swap = 4194288kB
> [18410.829275] 2031438 pages RAM
> [18410.829276] 0 pages HighMem/MovableOnly
> [18410.829277] 57497 pages reserved

OK we should look at this. It's annoying to rely on order-5 allocation when you
are debugging a memory leak issue. There should better be an order-0 fallback...

> I'll try to repeat the process with the 4.2.0-rc6 kernel also.

Hm I guess the memory stats for rc6 already rule out such high usage in ttm.

In rc7 it might be interesting to know how the page owner stats change after you
kill 1) the chrome/iceweasel processes, and then 2) the whole X. If the memory
is recovered, it might be not a full leak, but something like insufficient
shrinker response to memory pressure in the system.

Unless of course the drm devs have better ideas what to try...

> Arthur.
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1211138

Vlastimil Babka wrote on 21/08/15 21:07:
> On 08/21/2015 11:17 AM, Arthur Marsh wrote:
>>
>>
>> Vlastimil Babka wrote on 20/08/15 17:46:
>>> On 08/19/2015 05:44 PM, Arthur Marsh wrote:
>>>> Hi, I've found that the Linus' git head kernel has had some unwelcome
>>>> behaviour where chromium browser would exhaust all swap space in the
>>>> course of a few hours. The behaviour appeared before the release of
>>>> 4.2.0-rc7.
>>>
>>> Do you have any more details about the memory/swap usage? Is it really
>>> that chromium process(es) itself eats more memory and starts swapping,
>>> or that something else (a graphics driver?) eats kernel memory, and
>>> chromium as one of the biggest processes is driven to swap by that? Can
>>> you provide e.g. top output with good/bad kernels?
>>>
>>> Also what does /proc/meminfo and /proc/zoneinfo look like when it's
>>> swapping?
>>>
>>> To see which processes use swap, you can try [1] :
>>> for file in /proc/*/status ; do awk '/VmSwap|Name/{printf $2 " " $3}END{
>>> print ""}' $file; done | sort -k 2 -n -r | less
>>>
>>> Thanks
>>>
>>> [1] http://www.cyberciti.biz/faq/linux-which-process-is-using-swap/
>>>
>>>> This does not happen with kernel 4.2.0-rc6.
>>
>> Sorry for the delay in replying. I had to give an extended run under
>> kernel 4.2.0-rc6 to obtain comparative results. Both kernels' config
>> files are attached.
>>
>> The applications running are the same both times, mainly iceweasel
>> 38.1.0esr-3 and chromium 44.0.2403.107-1.
>>
>> With the rc7+ kernel but not the rc6 kernel, chromium eventually gets
>> into a state of consuming lots of swap.
>>
>> I was able to capture the output requested when running a 4.2.0-rc7+
>> kernel (Linus' git head as of around 05:00 UTC 19 August 2015) just
>> before swap was exhausted, forcing me to do a control-alt-delete
>> shutdown and waiting ages. The kernel config for the rc7+ is attached
>>
>> The comparison good kernel is from Debian:
>> Linux am64 4.2.0-rc6-amd64 #1 SMP Debian 4.2~rc6-1~exp1 (2015-08-12)
>> x86_64 GNU/Linux
>
> Hm I didn't how similar are the configs, was the debian one used as a
> base for the self-compiled one? Just to rule out config differences...
> during the bisection you did use the same for compiling a "good" rc6
> kernel and "bad" rc7 kernel, right?
>
> That, said, looking at the memory values:
>
> rc6: Free+Buffers+A/I(Anon)+A/I(File)+Slab = 6769MB
> rc7: ...                                   = 4714MB
>
> That's 2GB unaccounted for. Which is bad, and yet not enough to explain
> a full 4GB swap. Another noticeable difference is rc7 using 1560MB ShMem
> vs 476MB. The rest must be due to more anonymous memory used by the
> processes. Iceweasel looks unchanged, so I'm guessing the chromiums...
> the top output probably doesn't give us the whole picture here. I'm
> still suspecting a graphics driver, which one do you use?
>
> The shmem could be inspected by listing ipcs -m and ipcs -mp and grep
> grep SYSV /proc/*/maps and figuring out what processes are behind the
> pids. Doing that for rc6 and rc7 could tell us which processes use the
> extra 1GB of shmem in rc7.

I could do another test with the output you requested using an rc6 
kernel built with the same config as rc7 but it would mean the best part 
of 24 hours letting it run again.

I had observed the differences in behaviour with rc6 and rc7 kernels I 
had built with the same config, but it was difficult to bisect when the 
problems took some hours to appear.

The graphics driver is radeon, an onboard radeon 3200HD (RS780), taken 
from the r6 kernel dmesg (I have to do a power off restart with the 
onboard video to get it initialised correctly):

dmesg|egrep -i '(video|vga|radeon|agp|drm|ttm)'

[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-4.2.0-rc6-amd64 
root=UUID=39706f53-7c27-4310-b22a-36c7b042d1a1 ro radeon.audio=1
[    0.000000] AGP: No AGP bridge found
[    0.000000] Kernel command line: BOOT_IMAGE=/vmlinuz-4.2.0-rc6-amd64 
root=UUID=39706f53-7c27-4310-b22a-36c7b042d1a1 ro radeon.audio=1
[    0.000000] AGP: Checking aperture...
[    0.000000] AGP: No AGP bridge found
[    0.000000] AGP: Node 0: aperture [bus addr 0xe64000000-0xe65ffffff] 
(32MB)
[    0.000000] AGP: Your BIOS doesn't leave an aperture memory hole
[    0.000000] AGP: Please enable the IOMMU option in the BIOS setup
[    0.000000] AGP: This costs you 64MB of RAM
[    0.000000] AGP: Mapping aperture over RAM [mem 
0xb4000000-0xb7ffffff] (65536KB)
[    0.000000] Console: colour VGA+ 80x25
[    0.250485] vgaarb: setting as boot device: PCI:0000:01:05.0
[    0.250524] vgaarb: device added: 
PCI:0000:01:05.0,decodes=io+mem,owns=io+mem,locks=none
[    0.250562] vgaarb: loaded
[    0.250591] vgaarb: bridge control possible 0000:01:05.0
[    0.280443] pci 0000:01:05.0: Video device with shadowed ROM
[    0.554082] PCI-DMA: Disabling AGP.
[    0.554278] PCI-DMA: Reserving 64MB of IOMMU area in the AGP aperture
[    0.581841] Linux agpgart interface v0.103
[    8.192329] [drm] Initialized drm 1.1.0 20060810
[    9.820433] [drm] radeon kernel modesetting enabled.
[   10.061641] [drm] initializing kernel modesetting (RS780 
0x1002:0x9610 0x1043:0x82F1).
[   10.061723] [drm] register mmio base: 0xFEAF0000
[   10.061761] [drm] register mmio size: 65536
[   10.062752] radeon 0000:01:05.0: VRAM: 256M 0x00000000C0000000 - 
0x00000000CFFFFFFF (256M used)
[   10.062802] radeon 0000:01:05.0: GTT: 512M 0x00000000A0000000 - 
0x00000000BFFFFFFF
[   10.062848] [drm] Detected VRAM RAM=256M, BAR=256M
[   10.062886] [drm] RAM width 32bits DDR
[   10.063199] [TTM] Zone  kernel: Available graphics memory: 3961334 kiB
[   10.063242] [TTM] Zone   dma32: Available graphics memory: 2097152 kiB
[   10.063282] [TTM] Initializing pool allocator
[   10.063330] [TTM] Initializing DMA pool allocator
[   10.063415] [drm] radeon: 256M of VRAM memory ready
[   10.063457] [drm] radeon: 512M of GTT memory ready.
[   10.063521] [drm] Loading RS780 Microcode
[   10.375216] radeon 0000:01:05.0: firmware: direct-loading firmware 
radeon/RS780_pfp.bin
[   10.382622] radeon 0000:01:05.0: firmware: direct-loading firmware 
radeon/RS780_me.bin
[   10.418020] radeon 0000:01:05.0: firmware: direct-loading firmware 
radeon/R600_rlc.bin
[   10.418123] [drm] radeon: power management initialized
[   10.563323] radeon 0000:01:05.0: firmware: direct-loading firmware 
radeon/RS780_uvd.bin
[   10.563473] [drm] GART: num cpu pages 131072, num gpu pages 131072
[   10.582735] [drm] PCIE GART of 512M enabled (table at 
0x00000000C0258000).
[   10.582866] radeon 0000:01:05.0: WB enabled
[   10.582914] radeon 0000:01:05.0: fence driver on ring 0 use gpu addr 
0x00000000a0000c00 and cpu addr 0xffff8800bac13c00
[   10.587596] radeon 0000:01:05.0: fence driver on ring 5 use gpu addr 
0x00000000c0056038 and cpu addr 0xffffc90001016038
[   10.587667] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[   10.587706] [drm] Driver supports precise vblank timestamp query.
[   10.587746] radeon 0000:01:05.0: radeon: MSI limited to 32-bit
[   10.587806] [drm] radeon: irq initialized.
[   10.619604] [drm] ring test on 0 succeeded in 1 usecs
[   10.794153] [drm] ring test on 5 succeeded in 1 usecs
[   10.794217] [drm] UVD initialized successfully.
[   10.794840] [drm] ib test on ring 0 succeeded in 0 usecs
[   11.441315] [drm] ib test on ring 5 succeeded
[   11.442573] [drm] Radeon Display Connectors
[   11.442625] [drm] Connector 0:
[   11.442662] [drm]   VGA-1
[   11.442701] [drm]   DDC: 0x7e40 0x7e40 0x7e44 0x7e44 0x7e48 0x7e48 
0x7e4c 0x7e4c
[   11.442742] [drm]   Encoders:
[   11.442779] [drm]     CRT1: INTERNAL_KLDSCP_DAC1
[   11.442816] [drm] Connector 1:
[   11.442852] [drm]   HDMI-A-1
[   11.443780] [drm]   HPD3
[   11.443817] [drm]   DDC: 0x7e50 0x7e50 0x7e54 0x7e54 0x7e58 0x7e58 
0x7e5c 0x7e5c
[   11.443857] [drm]   Encoders:
[   11.443893] [drm]     DFP3: INTERNAL_KLDSCP_LVTMA
[   11.492369] [drm] fb mappable at 0xD0359000
[   11.492402] [drm] vram apper at 0xD0000000
[   11.492430] [drm] size 8294400
[   11.492458] [drm] fb depth is 24
[   11.492487] [drm]    pitch is 7680
[   11.492697] fbcon: radeondrmfb (fb0) is primary device
[   11.548492] radeon 0000:01:05.0: fb0: radeondrmfb frame buffer device
[   11.548581] radeon 0000:01:05.0: registered panic notifier
[   11.557161] [drm] Initialized radeon 2.43.0 20080528 for 0000:01:05.0 
on minor 0
[   12.615061] Linux video capture interface: v2.00

Arthur.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web