Re: excessive CPU utilization by isolate_freepages?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 06/28/2012 06:59 AM, Jim Schutt wrote:

> Hi,
> 
> I'm running into trouble with systems going unresponsive,
> and perf suggests it's excessive CPU usage by isolate_freepages().
> I'm currently testing 3.5-rc4, but I think this problem may have
> first shown up in 3.4.  I'm only just learning how to use perf,
> so I only currently have results to report for 3.5-rc4.
> 
> (FWIW I'm running the my distro version of perf; please let me know
> if I need to compile the tools/perf version to match my kernel.)
> 
> The systems in question have 24 SAS drives spread across 3 HBAs,
> running 24 Ceph OSD instances, one per drive.  FWIW these servers
> are dual-socket Intel 5675 Xeons w/48 GB memory.  I've got ~160
> Ceph Linux clients doing dd simultaneously to a Ceph file system
> backed by 12 of these servers.
> 
> In the early phase of such a test, when things are running well,
> here's what vmstat reports for the state of one of these servers:
> 
> 2012-06-27 13:56:58.356-06:00
> vmstat -w 4 16
> procs -------------------memory------------------ ---swap-- -----io----
> --system-- -----cpu-------
>  r  b       swpd       free       buff      cache   si   so    bi   
> bo   in   cs  us sy  id wa st
> 31 15          0     287216        576   38606628    0    0     2 
> 1158    2   14   1  3  95  0  0
> 27 15          0     225288        576   38583384    0    0    18
> 2222016 203357 134876  11 56  17 15  0
> 28 17          0     219256        576   38544736    0    0    11
> 2305932 203141 146296  11 49  23 17  0
>  6 18          0     215596        576   38552872    0    0     7
> 2363207 215264 166502  12 45  22 20  0
> 22 18          0     226984        576   38596404    0    0     3
> 2445741 223114 179527  12 43  23 22  0
> 30 12          0     230844        576   38461648    0    0    14
> 2298537 216580 166661  12 45  23 20  0
> 29 19          0     237856        576   38422884    0    0     5
> 2332741 209408 157138  12 42  25 22  0
> 17 11          0     222156        576   38483992    0    0     4
> 2380495 210312 173121  12 39  28 22  0
> 11 13          0     216152        576   38463872    0    0    44
> 2362186 215236 176454  12 39  27 22  0
> 12 14          0     223704        576   38546720    0    0     2
> 2395530 214684 177518  12 39  28 22  0
> 39 17          0     219932        576   38598184    0    0     4
> 2428231 223284 179095  12 42  24 21  0
> 11 10          0     219956        576   38521048    0    0     4
> 2323853 207472 166665  12 39  28 21  0
> 23 15          0     216580        576   38451904    0    0     3
> 2241800 201049 163496  11 37  31 21  0
>  9 13          0     225792        576   38451916    0    0    13
> 2281900 204869 171814  11 36  30 23  0
> 14 12          0     233820        576   38492728    0    0     4
> 2293423 207686 173019  11 37  31 21  0
> 11 20          0     213796        576   38533208    0    0     3
> 2288636 205605 168118  11 37  31 21  0
> 
> 
> The system begins to struggle over the next several
> minutes; here's what vmstat has to say:
> 
> 2012-06-27 13:57:58.831-06:00
> vmstat -w 4 16
> procs -------------------memory------------------ ---swap-- -----io----
> --system-- -----cpu-------
>  r  b       swpd       free       buff      cache   si   so    bi   
> bo   in   cs  us sy  id wa st
> 21 16          0     224628        576   38526872    0    0     2 
> 1233    9   19   1  4  95  0  0
> 12 19          0     232060        576   38501020    0    0     4
> 2366769 221418 159890  12 48  20 19  0
> 124  8          0     218548        576   38379656    0    0    13
> 2103075 199660 108618  11 65  13 12  0
> 24 10          0     300476        576   38230288    0    0    31
> 1966282 177472 84572  10 76   7  7  0
> 20 16          0     217584        576   38296700    0    0     9
> 2062571 195936 128810  10 55  20 15  0
> 53 12          0     235720        576   38247968    0    0    30
> 2035407 196973 133921  10 52  23 15  0
> 20 16          0     360340        576   38067992    0    0     6
> 2192179 208692 136784  11 54  19 15  0
> 26 10          0     310800        576   38093884    0    0    43
> 2138772 207105 118718  11 64  12 13  0
> 24 15          0     261108        576   38030828    0    0    68
> 2174015 205793 135302  11 56  18 15  0
>  9 17          0     241816        576   37982072    0    0    20
> 2076145 194971 120285  10 60  16 14  0
> 37 15          0     255972        576   37892868    0    0    14
> 2225076 205694 126954  11 59  16 13  0
> 27 16          0     243212        576   37872704    0    0     6
> 2249476 210885 134684  12 60  15 14  0
> 30 10          0     217572        576   37795388    0    0     3
> 2128688 205027 118319  11 66  12 11  0
> 26 11          0     236420        576   37740164    0    0    23
> 2109709 205105 133925  10 56  19 14  0
> 45 15          0     330056        576   37619896    0    0    15
> 1948311 196188 119330  10 62  15 13  0
> 54 15          0     242696        576   37631500    0    0     4
> 2159530 202595 132588  11 59  16 15  0
> 
> 2012-06-27 13:58:59.569-06:00
> vmstat -w 4 16
> procs -------------------memory------------------ ---swap-- -----io----
> --system-- -----cpu-------
>  r  b       swpd       free       buff      cache   si   so    bi   
> bo   in   cs  us sy  id wa st
> 14 15          0     274932        576   37621548    0    0     2 
> 1301   15    0   1  4  95  0  0
> 44 16          0     278748        576   37509516    0    0     6
> 2097643 196722 112697  10 66  12 11  0
> 88 14          0     228088        576   37412008    0    0     6
> 2089559 202206 116146  10 66  13 11  0
> 94 11          0     348348        576   37270624    0    0     7
> 1906390 181488 87333   9 76   9  6  0
> 42 11          0     215996        576   37288556    0    0     6
> 1782459 184375 95901   9 74   9  7  0
> 45 11          0     323112        576   37146500    0    0    12
> 1868376 187814 103947   9 71  11  9  0
> 51  7          0     244560        576   37100124    0    0    35
> 1767496 181383 107259   9 68  12 11  0
> 74 12          0     221584        576   37016420    0    0    18
> 1884986 183376 93425   9 75   9  7  0
> 45 10          0     275564        576   36985324    0    0    23
> 1683688 167223 97036   8 75   9  8  0
> 19 10          0     322176        576   36813176    0    0    14
> 1747378 177594 97218   8 72  12  8  0
> 122  7          0     225256        576   36838084    0    0    26
> 1730643 177915 92621   8 75   9  8  0
> 243 10          0     223464        576   36765460    0    0    18
> 1730158 173059 79373   8 80   6  5  0
> 100 10          0     307528        576   36598456    0    0     4
> 1738567 174077 79585   9 82   6  4  0
> 243  6          0     370064        576   36358576    0    0     9
> 1586528 174680 85353   8 81   6  5  0
> 267  2          0     322640        576   36254044    0    0    40
> 1011650 129389 42277   5 93   1  1  0
> 210  4          0     505092        576   35865460    0    0    25
> 720825 116356 32422   3 96   1  0  0
> 
> 2012-06-27 14:00:03.219-06:00
> vmstat -w 4 16
> procs -------------------memory------------------ ---swap-- -----io----
> --system-- -----cpu-------
>  r  b       swpd       free       buff      cache   si   so    bi   
> bo   in   cs  us sy  id wa st
> 75  1          0     566988        576   35664800    0    0     2 
> 1355   21    3   1  4  95  0  0
> 433  1          0     964052        576   35069112    0    0     7
> 456359 102256 20901   2 98   0  0  0
> 547  3          0     820116        576   34893932    0    0    57
> 560507 114878 28115   3 96   0  0  0
> 806  2          0     606992        576   34848180    0    0   339
> 309668 101230 21056   2 98   0  0  0
> 708  1          0     529624        576   34708000    0    0   248
> 370886 101327 20062   2 97   0  0  0
> 231  5          0     504772        576   34663880    0    0   305
> 334824 95045 20407   2 97   1  1  0
> 158  6          0    1063088        576   33518536    0    0   531
> 847435 130696 47140   4 92   1  2  0
> 193  0          0    1449156        576   33035572    0    0   363
> 371279 94470 18955   2 96   1  1  0
> 266  6          0    1623512        576   32728164    0    0    77
> 241114 95730 15483   2 98   0  0  0
> 243  8          0    1629504        576   32653080    0    0    81
> 471018 100223 20920   3 96   0  1  0
> 70 11          0    1342140        576   33084020    0    0   100 925869
> 139876 56599   6 88   3  3  0
> 211  7          0    1130316        576   33470432    0    0   290
> 1008984 150699 74320   6 83   6  5  0
> 365  3          0     776736        576   34072772    0    0   182
> 747167 139436 67135   5 88   4  3  0
> 29  1          0    1528412        576   34110640    0    0    50 612181
> 137403 77609   4 87   6  3  0
> 266  5          0    1657688        576   34105696    0    0     3
> 258307 62879 38508   2 93   3  2  0
> 1159  2          0    2002256        576   33775476    0    0    19
> 88554 42112 14230   1 98   0  0  0
> 
> 
> Right around 14:00 I was able to get a "perf -a -g"; here's the
> beginning of what "perf report --sort symbol --call-graph fractal,5"
> had to say:
> 
> #
>     64.86%  [k] _raw_spin_lock_irqsave
>             |
>             |--97.94%-- isolate_freepages
>             |          compaction_alloc
>             |          unmap_and_move
>             |          migrate_pages
>             |          compact_zone
>             |          |
>             |          |--99.56%-- try_to_compact_pages
>             |          |          __alloc_pages_direct_compact
>             |          |          __alloc_pages_slowpath
>             |          |          __alloc_pages_nodemask
>             |          |          alloc_pages_vma
>             |          |          do_huge_pmd_anonymous_page
>             |          |          handle_mm_fault
>             |          |          do_page_fault
>             |          |          page_fault
>             |          |          |
>             |          |          |--53.53%-- skb_copy_datagram_iovec
>             |          |          |          tcp_recvmsg
>             |          |          |          inet_recvmsg
>             |          |          |          sock_recvmsg
>             |          |          |          sys_recvfrom
>             |          |          |          system_call_fastpath
>             |          |          |          __recv
>             |          |          |          |
>             |          |          |           --100.00%-- (nil)
>             |          |          |
>             |          |          |--27.80%-- __pthread_create_2_1
>             |          |          |          (nil)
>             |          |          |
>             |          |           --18.67%-- memcpy
>             |          |                     |
>             |          |                     |--57.38%-- 0x50d000005
>             |          |                     |
>             |          |                     |--34.52%-- 0x3b300bf271940a35
>             |          |                     |
>             |          |                      --8.10%-- 0x1500000000000009
>             |           --0.44%-- [...]
>              --2.06%-- [...]
> 
>      6.15%  [k] isolate_freepages_block
>             |
>             |--99.95%-- isolate_freepages
>             |          compaction_alloc
>             |          unmap_and_move
>             |          migrate_pages
>             |          compact_zone
>             |          |
>             |          |--99.54%-- try_to_compact_pages
>             |          |          __alloc_pages_direct_compact
>             |          |          __alloc_pages_slowpath
>             |          |          __alloc_pages_nodemask
>             |          |          alloc_pages_vma
>             |          |          do_huge_pmd_anonymous_page
>             |          |          handle_mm_fault
>             |          |          do_page_fault
>             |          |          page_fault
>             |          |          |
>             |          |          |--54.40%-- skb_copy_datagram_iovec
>             |          |          |          tcp_recvmsg
>             |          |          |          inet_recvmsg
>             |          |          |          sock_recvmsg
>             |          |          |          sys_recvfrom
>             |          |          |          system_call_fastpath
>             |          |          |          __recv
>             |          |          |          |
>             |          |          |           --100.00%-- (nil)
>             |          |          |
>             |          |          |--25.19%-- __pthread_create_2_1
>             |          |          |          (nil)
>             |          |          |
>             |          |           --20.41%-- memcpy
>             |          |                     |
>             |          |                     |--40.24%-- 0x3b300bf271940a35
>             |          |                     |
>             |          |                     |--38.29%-- 0x1500000000000009
>             |          |                     |
>             |          |                      --21.47%-- 0x50d000005
>             |           --0.46%-- [...]
>              --0.05%-- [...]
> 
>      3.96%  [.] ceph_crc32c_le
>             |
>             |--99.99%-- 0xb8057558d0065990
>              --0.01%-- [...]
> 
> A different system in the same test had a slightly different
> call tree, but isolate_freepages() still seems to show up
> prominently:
> 
> #
>     32.32%  [k] _raw_spin_lock_irqsave
>             |
>             |--97.64%-- isolate_freepages
>             |          compaction_alloc
>             |          unmap_and_move
>             |          migrate_pages
>             |          compact_zone
>             |          try_to_compact_pages
>             |          __alloc_pages_direct_compact
>             |          __alloc_pages_slowpath
>             |          __alloc_pages_nodemask
>             |          alloc_pages_vma
>             |          do_huge_pmd_anonymous_page
>             |          handle_mm_fault
>             |          do_page_fault
>             |          page_fault
>             |          |
>             |          |--65.31%-- skb_copy_datagram_iovec
>             |          |          tcp_recvmsg
>             |          |          inet_recvmsg
>             |          |          sock_recvmsg
>             |          |          sys_recvfrom
>             |          |          system_call_fastpath
>             |          |          __recv
>             |          |          |
>             |          |           --100.00%-- (nil)
>             |          |
>             |          |--30.98%-- memcpy
>             |          |          |
>             |          |          |--50.60%-- 0x50d0000
>             |          |          |
>             |          |           --49.40%-- 0x50d000005
>             |           --3.70%-- [...]
>              --2.36%-- [...]
> 
>     17.10%  [k] _raw_spin_lock_irq
>             |
>             |--98.27%-- isolate_migratepages_range
>             |          compact_zone
>             |          try_to_compact_pages
>             |          __alloc_pages_direct_compact
>             |          __alloc_pages_slowpath
>             |          __alloc_pages_nodemask
>             |          alloc_pages_vma
>             |          do_huge_pmd_anonymous_page
>             |          handle_mm_fault
>             |          do_page_fault
>             |          page_fault
>             |          |
>             |          |--99.85%-- __pthread_create_2_1
>             |          |          (nil)
>             |           --0.15%-- [...]
>              --1.73%-- [...]
> 
>      4.59%  [k] mutex_spin_on_owner
>             |
>             --- __mutex_lock_slowpath
>                 mutex_lock
>                |
>                |--50.14%-- page_lock_anon_vma
>                |          |
>                |          |--99.99%-- try_to_unmap_anon
>                |          |          try_to_unmap
>                |          |          __unmap_and_move
>                |          |          unmap_and_move
>                |          |          migrate_pages
>                |          |          compact_zone
>                |          |          try_to_compact_pages
>                |          |          __alloc_pages_direct_compact
>                |          |          __alloc_pages_slowpath
>                |          |          __alloc_pages_nodemask
>                |          |          alloc_pages_vma
>                |          |          do_huge_pmd_anonymous_page
>                |          |          handle_mm_fault
>                |          |          do_page_fault
>                |          |          page_fault
>                |          |          |
>                |          |          |--99.91%-- __pthread_create_2_1
>                |          |          |          (nil)
>                |          |           --0.09%-- [...]
>                |           --0.01%-- [...]
>                |
>                |--49.67%-- rmap_walk
>                |          move_to_new_page
>                |          __unmap_and_move
>                |          unmap_and_move
>                |          migrate_pages
>                |          compact_zone
>                |          try_to_compact_pages
>                |          __alloc_pages_direct_compact
>                |          __alloc_pages_slowpath
>                |          __alloc_pages_nodemask
>                |          alloc_pages_vma
>                |          do_huge_pmd_anonymous_page
>                |          handle_mm_fault
>                |          do_page_fault
>                |          page_fault
>                |          |
>                |          |--99.69%-- __pthread_create_2_1
>                |          |          (nil)
>                |           --0.31%-- [...]
>                 --0.20%-- [...]
> 
>      4.10%  [k] isolate_freepages_block
>             |
>             |--99.95%-- isolate_freepages
>             |          compaction_alloc
>             |          unmap_and_move
>             |          migrate_pages
>             |          compact_zone
>             |          try_to_compact_pages
>             |          __alloc_pages_direct_compact
>             |          __alloc_pages_slowpath
>             |          __alloc_pages_nodemask
>             |          alloc_pages_vma
>             |          do_huge_pmd_anonymous_page
>             |          handle_mm_fault
>             |          do_page_fault
>             |          page_fault
>             |          |
>             |          |--46.97%-- skb_copy_datagram_iovec
>             |          |          tcp_recvmsg
>             |          |          inet_recvmsg
>             |          |          sock_recvmsg
>             |          |          sys_recvfrom
>             |          |          system_call_fastpath
>             |          |          __recv
>             |          |          |
>             |          |           --100.00%-- (nil)
>             |          |
>             |          |--31.79%-- __pthread_create_2_1
>             |          |          (nil)
>             |          |
>             |           --21.24%-- memcpy
>             |                     |
>             |                     |--61.90%-- 0x50d000005
>             |                     |
>             |                      --38.10%-- 0x50d0000
>              --0.05%-- [...]
> 
>      3.65%  [.] ceph_crc32c_le
>             |
>             |--99.86%-- 0xb8057558d0065990
>              --0.14%-- [...]
> 
> 
> 
> I seem to be able to recreate this issue at will, so please
> let me know what I can do to help learn what is going on.
> 
> Thanks -- Jim



I doubt compaction try to migrate continuously although we have no free memory.
Could you apply this patch and retest?

https://lkml.org/lkml/2012/6/21/30

Thanks.

-- 
Kind regards,
Minchan Kim

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@xxxxxxxxx.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@xxxxxxxxx";> email@xxxxxxxxx </a>


[Index of Archives]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [ECOS]     [Asterisk Internet PBX]     [Linux API]