)]}' { "log": [ { "commit": "7a2d19bced51af31d2c9ff55219400ed0a6c012f", "tree": "03185e2121499942b9f2f95c50a86abd4d9fce1c", "parents": [ "dd9e5efe3aa9fc5b1ce484a531ecdba3a7a30bbf" ], "author": { "name": "Mel Gorman", "email": "mel@csn.ul.ie", "time": "Tue Dec 21 17:24:18 2010 -0800" }, "committer": { "name": "Linus Torvalds", "email": "torvalds@linux-foundation.org", "time": "Wed Dec 22 19:43:33 2010 -0800" }, "message": "mm: vmscan: tracepoint: account for scanned pages similarly for both ftrace and vmstat\n\nWhen correlating ftrace results with /proc/vmstat, I noticed that the\nreporting scripts value for \"pages scanned\" differed significantly. Both\nvalues were \"right\" depending on how you look at it.\n\nThe difference is due to vmstat only counting scanning of the inactive\nlist towards pages scanned. The analysis script for the tracepoint counts\nactive and inactive list yielding a far higher value than vmstat. The\nresulting scanning/reclaim ratio looks much worse. The tracepoint is ok\nbut this patch updates the reporting script so that the report values for\nscanned are similar to vmstat.\n\nSigned-off-by: Mel Gorman \u003cmel@csn.ul.ie\u003e\nSigned-off-by: Andrew Morton \u003cakpm@linux-foundation.org\u003e\nSigned-off-by: Linus Torvalds \u003ctorvalds@linux-foundation.org\u003e\n" }, { "commit": "e11da5b4fdf01d71d73c21cb92b00595b917d7fd", "tree": "30da286bac7533fba5c119396491ab05a92471fd", "parents": [ "66d9a986cddbbc2ea5db013e7999c621a956cc47" ], "author": { "name": "Mel Gorman", "email": "mel@csn.ul.ie", "time": "Tue Oct 26 14:21:40 2010 -0700" }, "committer": { "name": "Linus Torvalds", "email": "torvalds@linux-foundation.org", "time": "Tue Oct 26 16:52:07 2010 -0700" }, "message": "tracing, vmscan: add trace events for LRU list shrinking\n\nThere have been numerous reports of stalls that pointed at the problem\nbeing somewhere in the VM. There are multiple roots to the problems which\nmeans dealing with any of the root problems in isolation is tricky to\njustify on their own and they would still need integration testing. This\npatch series puts together two different patch sets which in combination\nshould tackle some of the root causes of latency problems being reported.\n\nPatch 1 adds a tracepoint for shrink_inactive_list. For this series, the\nmost important results is being able to calculate the scanning/reclaim\nratio as a measure of the amount of work being done by page reclaim.\n\nPatch 2 accounts for time spent in congestion_wait.\n\nPatches 3-6 were originally developed by Kosaki Motohiro but reworked for\nthis series. It has been noted that lumpy reclaim is far too aggressive\nand trashes the system somewhat. As SLUB uses high-order allocations, a\nlarge cost incurred by lumpy reclaim will be noticeable. It was also\nreported during transparent hugepage support testing that lumpy reclaim\nwas trashing the system and these patches should mitigate that problem\nwithout disabling lumpy reclaim.\n\nPatch 7 adds wait_iff_congested() and replaces some callers of\ncongestion_wait(). wait_iff_congested() only sleeps if there is a BDI\nthat is currently congested. Patch 8 notes that any BDI being congested\nis not necessarily a problem because there could be multiple BDIs of\nvarying speeds and numberous zones. It attempts to track when a zone\nbeing reclaimed contains many pages backed by a congested BDI and if so,\nreclaimers wait on the congestion queue.\n\nI ran a number of tests with monitoring on X86, X86-64 and PPC64. Each\nmachine had 3G of RAM and the CPUs were\n\nX86: Intel P4 2-core\nX86-64: AMD Phenom 4-core\nPPC64: PPC970MP\n\nEach used a single disk and the onboard IO controller. Dirty ratio was\nleft at 20. I\u0027m just going to report for X86-64 and PPC64 in a vague\nattempt to keep this report short. Four kernels were tested each based on\nv2.6.36-rc4\n\ntraceonly-v2r2: Patches 1 and 2 to instrument vmscan reclaims and congestion_wait\nlowlumpy-v2r3: Patches 1-6 to test if lumpy reclaim is better\nwaitcongest-v2r3: Patches 1-7 to only wait on congestion\nwaitwriteback-v2r4: Patches 1-8 to detect when a zone is congested\n\nnocongest-v1r5: Patches 1-3 for testing wait_iff_congestion\nnodirect-v1r5: Patches 1-10 to disable filesystem writeback for better IO\n\nThe tests run were as follows\n\nkernbench\n\tcompile-based benchmark. Smoke test performance\n\nsysbench\n\tOLTP read-only benchmark. Will be re-run in the future as read-write\n\nmicro-mapped-file-stream\n\tThis is a micro-benchmark from Johannes Weiner that accesses a\n\tlarge sparse-file through mmap(). It was configured to run in only\n\tsingle-CPU mode but can be indicative of how well page reclaim\n\tidentifies suitable pages.\n\nstress-highalloc\n\tTries to allocate huge pages under heavy load.\n\nkernbench, iozone and sysbench did not report any performance regression\non any machine. sysbench did pressure the system lightly and there was\nreclaim activity but there were no difference of major interest between\nthe kernels.\n\nX86-64 micro-mapped-file-stream\n\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3 waitwriteback-v2r4\npgalloc_dma 1639.00 ( 0.00%) 667.00 (-145.73%) 1167.00 ( -40.45%) 578.00 (-183.56%)\npgalloc_dma32 2842410.00 ( 0.00%) 2842626.00 ( 0.01%) 2843043.00 ( 0.02%) 2843014.00 ( 0.02%)\npgalloc_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgsteal_dma 729.00 ( 0.00%) 85.00 (-757.65%) 609.00 ( -19.70%) 125.00 (-483.20%)\npgsteal_dma32 2338721.00 ( 0.00%) 2447354.00 ( 4.44%) 2429536.00 ( 3.74%) 2436772.00 ( 4.02%)\npgsteal_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgscan_kswapd_dma 1469.00 ( 0.00%) 532.00 (-176.13%) 1078.00 ( -36.27%) 220.00 (-567.73%)\npgscan_kswapd_dma32 4597713.00 ( 0.00%) 4503597.00 ( -2.09%) 4295673.00 ( -7.03%) 3891686.00 ( -18.14%)\npgscan_kswapd_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgscan_direct_dma 71.00 ( 0.00%) 134.00 ( 47.01%) 243.00 ( 70.78%) 352.00 ( 79.83%)\npgscan_direct_dma32 305820.00 ( 0.00%) 280204.00 ( -9.14%) 600518.00 ( 49.07%) 957485.00 ( 68.06%)\npgscan_direct_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npageoutrun 16296.00 ( 0.00%) 21254.00 ( 23.33%) 18447.00 ( 11.66%) 20067.00 ( 18.79%)\nallocstall 443.00 ( 0.00%) 273.00 ( -62.27%) 513.00 ( 13.65%) 1568.00 ( 71.75%)\n\nThese are based on the raw figures taken from /proc/vmstat. It\u0027s a rough\nmeasure of reclaim activity. Note that allocstall counts are higher\nbecause we are entering direct reclaim more often as a result of not\nsleeping in congestion. In itself, it\u0027s not necessarily a bad thing.\nIt\u0027s easier to get a view of what happened from the vmscan tracepoint\nreport.\n\nFTrace Reclaim Statistics: vmscan\n\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3 waitwriteback-v2r4\nDirect reclaims 443 273 513 1568\nDirect reclaim pages scanned 305968 280402 600825 957933\nDirect reclaim pages reclaimed 43503 19005 30327 117191\nDirect reclaim write file async I/O 0 0 0 0\nDirect reclaim write anon async I/O 0 3 4 12\nDirect reclaim write file sync I/O 0 0 0 0\nDirect reclaim write anon sync I/O 0 0 0 0\nWake kswapd requests 187649 132338 191695 267701\nKswapd wakeups 3 1 4 1\nKswapd pages scanned 4599269 4454162 4296815 3891906\nKswapd pages reclaimed 2295947 2428434 2399818 2319706\nKswapd reclaim write file async I/O 1 0 1 1\nKswapd reclaim write anon async I/O 59 187 41 222\nKswapd reclaim write file sync I/O 0 0 0 0\nKswapd reclaim write anon sync I/O 0 0 0 0\nTime stalled direct reclaim (seconds) 4.34 2.52 6.63 2.96\nTime kswapd awake (seconds) 11.15 10.25 11.01 10.19\n\nTotal pages scanned 4905237 4734564 4897640 4849839\nTotal pages reclaimed 2339450 2447439 2430145 2436897\n%age total pages scanned/reclaimed 47.69% 51.69% 49.62% 50.25%\n%age total pages scanned/written 0.00% 0.00% 0.00% 0.00%\n%age file pages scanned/written 0.00% 0.00% 0.00% 0.00%\nPercentage Time Spent Direct Reclaim 29.23% 19.02% 38.48% 20.25%\nPercentage Time kswapd Awake 78.58% 78.85% 76.83% 79.86%\n\nWhat is interesting here for nocongest in particular is that while direct\nreclaim scans more pages, the overall number of pages scanned remains the\nsame and the ratio of pages scanned to pages reclaimed is more or less the\nsame. In other words, while we are sleeping less, reclaim is not doing\nmore work and as direct reclaim and kswapd is awake for less time, it\nwould appear to be doing less work.\n\nFTrace Reclaim Statistics: congestion_wait\nDirect number congest waited 87 196 64 0\nDirect time congest waited 4604ms 4732ms 5420ms 0ms\nDirect full congest waited 72 145 53 0\nDirect number conditional waited 0 0 324 1315\nDirect time conditional waited 0ms 0ms 0ms 0ms\nDirect full conditional waited 0 0 0 0\nKSwapd number congest waited 20 10 15 7\nKSwapd time congest waited 1264ms 536ms 884ms 284ms\nKSwapd full congest waited 10 4 6 2\nKSwapd number conditional waited 0 0 0 0\nKSwapd time conditional waited 0ms 0ms 0ms 0ms\nKSwapd full conditional waited 0 0 0 0\n\nThe vanilla kernel spent 8 seconds asleep in direct reclaim and no time at\nall asleep with the patches.\n\nMMTests Statistics: duration\nUser/Sys Time Running Test (seconds) 10.51 10.73 10.6 11.66\nTotal Elapsed Time (seconds) 14.19 13.00 14.33 12.76\n\nOverall, the tests completed faster. It is interesting to note that backing off further\nwhen a zone is congested and not just a BDI was more efficient overall.\n\nPPC64 micro-mapped-file-stream\npgalloc_dma 3024660.00 ( 0.00%) 3027185.00 ( 0.08%) 3025845.00 ( 0.04%) 3026281.00 ( 0.05%)\npgalloc_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgsteal_dma 2508073.00 ( 0.00%) 2565351.00 ( 2.23%) 2463577.00 ( -1.81%) 2532263.00 ( 0.96%)\npgsteal_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgscan_kswapd_dma 4601307.00 ( 0.00%) 4128076.00 ( -11.46%) 3912317.00 ( -17.61%) 3377165.00 ( -36.25%)\npgscan_kswapd_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npgscan_direct_dma 629825.00 ( 0.00%) 971622.00 ( 35.18%) 1063938.00 ( 40.80%) 1711935.00 ( 63.21%)\npgscan_direct_normal 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%) 0.00 ( 0.00%)\npageoutrun 27776.00 ( 0.00%) 20458.00 ( -35.77%) 18763.00 ( -48.04%) 18157.00 ( -52.98%)\nallocstall 977.00 ( 0.00%) 2751.00 ( 64.49%) 2098.00 ( 53.43%) 5136.00 ( 80.98%)\n\nSimilar trends to x86-64. allocstalls are up but it\u0027s not necessarily bad.\n\nFTrace Reclaim Statistics: vmscan\nDirect reclaims 977 2709 2098 5136\nDirect reclaim pages scanned 629825 963814 1063938 1711935\nDirect reclaim pages reclaimed 75550 242538 150904 387647\nDirect reclaim write file async I/O 0 0 0 2\nDirect reclaim write anon async I/O 0 10 0 4\nDirect reclaim write file sync I/O 0 0 0 0\nDirect reclaim write anon sync I/O 0 0 0 0\nWake kswapd requests 392119 1201712 571935 571921\nKswapd wakeups 3 2 3 3\nKswapd pages scanned 4601307 4128076 3912317 3377165\nKswapd pages reclaimed 2432523 2318797 2312673 2144616\nKswapd reclaim write file async I/O 20 1 1 1\nKswapd reclaim write anon async I/O 57 132 11 121\nKswapd reclaim write file sync I/O 0 0 0 0\nKswapd reclaim write anon sync I/O 0 0 0 0\nTime stalled direct reclaim (seconds) 6.19 7.30 13.04 10.88\nTime kswapd awake (seconds) 21.73 26.51 25.55 23.90\n\nTotal pages scanned 5231132 5091890 4976255 5089100\nTotal pages reclaimed 2508073 2561335 2463577 2532263\n%age total pages scanned/reclaimed 47.95% 50.30% 49.51% 49.76%\n%age total pages scanned/written 0.00% 0.00% 0.00% 0.00%\n%age file pages scanned/written 0.00% 0.00% 0.00% 0.00%\nPercentage Time Spent Direct Reclaim 18.89% 20.65% 32.65% 27.65%\nPercentage Time kswapd Awake 72.39% 80.68% 78.21% 77.40%\n\nAgain, a similar trend that the congestion_wait changes mean that direct\nreclaim scans more pages but the overall number of pages scanned while\nslightly reduced, are very similar. The ratio of scanning/reclaimed\nremains roughly similar. The downside is that kswapd and direct reclaim\nwas awake longer and for a larger percentage of the overall workload.\nIt\u0027s possible there were big differences in the amount of time spent\nreclaiming slab pages between the different kernels which is plausible\nconsidering that the micro tests runs after fsmark and sysbench.\n\nTrace Reclaim Statistics: congestion_wait\nDirect number congest waited 845 1312 104 0\nDirect time congest waited 19416ms 26560ms 7544ms 0ms\nDirect full congest waited 745 1105 72 0\nDirect number conditional waited 0 0 1322 2935\nDirect time conditional waited 0ms 0ms 12ms 312ms\nDirect full conditional waited 0 0 0 3\nKSwapd number congest waited 39 102 75 63\nKSwapd time congest waited 2484ms 6760ms 5756ms 3716ms\nKSwapd full congest waited 20 48 46 25\nKSwapd number conditional waited 0 0 0 0\nKSwapd time conditional waited 0ms 0ms 0ms 0ms\nKSwapd full conditional waited 0 0 0 0\n\nThe vanilla kernel spent 20 seconds asleep in direct reclaim and only\n312ms asleep with the patches. The time kswapd spent congest waited was\nalso reduced by a large factor.\n\nMMTests Statistics: duration\nser/Sys Time Running Test (seconds) 26.58 28.05 26.9 28.47\nTotal Elapsed Time (seconds) 30.02 32.86 32.67 30.88\n\nWith all patches applies, the completion times are very similar.\n\nX86-64 STRESS-HIGHALLOC\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3waitwriteback-v2r4\nPass 1 82.00 ( 0.00%) 84.00 ( 2.00%) 85.00 ( 3.00%) 85.00 ( 3.00%)\nPass 2 90.00 ( 0.00%) 87.00 (-3.00%) 88.00 (-2.00%) 89.00 (-1.00%)\nAt Rest 92.00 ( 0.00%) 90.00 (-2.00%) 90.00 (-2.00%) 91.00 (-1.00%)\n\nSuccess figures across the board are broadly similar.\n\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3waitwriteback-v2r4\nDirect reclaims 1045 944 886 887\nDirect reclaim pages scanned 135091 119604 109382 101019\nDirect reclaim pages reclaimed 88599 47535 47863 46671\nDirect reclaim write file async I/O 494 283 465 280\nDirect reclaim write anon async I/O 29357 13710 16656 13462\nDirect reclaim write file sync I/O 154 2 2 3\nDirect reclaim write anon sync I/O 14594 571 509 561\nWake kswapd requests 7491 933 872 892\nKswapd wakeups 814 778 731 780\nKswapd pages scanned 7290822 15341158 11916436 13703442\nKswapd pages reclaimed 3587336 3142496 3094392 3187151\nKswapd reclaim write file async I/O 91975 32317 28022 29628\nKswapd reclaim write anon async I/O 1992022 789307 829745 849769\nKswapd reclaim write file sync I/O 0 0 0 0\nKswapd reclaim write anon sync I/O 0 0 0 0\nTime stalled direct reclaim (seconds) 4588.93 2467.16 2495.41 2547.07\nTime kswapd awake (seconds) 2497.66 1020.16 1098.06 1176.82\n\nTotal pages scanned 7425913 15460762 12025818 13804461\nTotal pages reclaimed 3675935 3190031 3142255 3233822\n%age total pages scanned/reclaimed 49.50% 20.63% 26.13% 23.43%\n%age total pages scanned/written 28.66% 5.41% 7.28% 6.47%\n%age file pages scanned/written 1.25% 0.21% 0.24% 0.22%\nPercentage Time Spent Direct Reclaim 57.33% 42.15% 42.41% 42.99%\nPercentage Time kswapd Awake 43.56% 27.87% 29.76% 31.25%\n\nScanned/reclaimed ratios again look good with big improvements in\nefficiency. The Scanned/written ratios also look much improved. With a\nbetter scanned/written ration, there is an expectation that IO would be\nmore efficient and indeed, the time spent in direct reclaim is much\nreduced by the full series and kswapd spends a little less time awake.\n\nOverall, indications here are that allocations were happening much faster\nand this can be seen with a graph of the latency figures as the\nallocations were taking place\nhttp://www.csn.ul.ie/~mel/postings/vmscanreduce-20101509/highalloc-interlatency-hydra-mean.ps\n\nFTrace Reclaim Statistics: congestion_wait\nDirect number congest waited 1333 204 169 4\nDirect time congest waited 78896ms 8288ms 7260ms 200ms\nDirect full congest waited 756 92 69 2\nDirect number conditional waited 0 0 26 186\nDirect time conditional waited 0ms 0ms 0ms 2504ms\nDirect full conditional waited 0 0 0 25\nKSwapd number congest waited 4 395 227 282\nKSwapd time congest waited 384ms 25136ms 10508ms 18380ms\nKSwapd full congest waited 3 232 98 176\nKSwapd number conditional waited 0 0 0 0\nKSwapd time conditional waited 0ms 0ms 0ms 0ms\nKSwapd full conditional waited 0 0 0 0\nKSwapd full conditional waited 318 0 312 9\n\nOverall, the time spent speeping is reduced. kswapd is still hitting\ncongestion_wait() but that is because there are callers remaining where it\nwasn\u0027t clear in advance if they should be changed to wait_iff_congested()\nor not. Overall the sleep imes are reduced though - from 79ish seconds to\nabout 19.\n\nMMTests Statistics: duration\nUser/Sys Time Running Test (seconds) 3415.43 3386.65 3388.39 3377.5\nTotal Elapsed Time (seconds) 5733.48 3660.33 3689.41 3765.39\n\nWith the full series, the time to complete the tests are reduced by 30%\n\nPPC64 STRESS-HIGHALLOC\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3waitwriteback-v2r4\nPass 1 17.00 ( 0.00%) 34.00 (17.00%) 38.00 (21.00%) 43.00 (26.00%)\nPass 2 25.00 ( 0.00%) 37.00 (12.00%) 42.00 (17.00%) 46.00 (21.00%)\nAt Rest 49.00 ( 0.00%) 43.00 (-6.00%) 45.00 (-4.00%) 51.00 ( 2.00%)\n\nSuccess rates there are *way* up particularly considering that the 16MB\nhuge pages on PPC64 mean that it\u0027s always much harder to allocate them.\n\nFTrace Reclaim Statistics: vmscan\n stress-highalloc stress-highalloc stress-highalloc stress-highalloc\n traceonly-v2r2 lowlumpy-v2r3 waitcongest-v2r3waitwriteback-v2r4\nDirect reclaims 499 505 564 509\nDirect reclaim pages scanned 223478 41898 51818 45605\nDirect reclaim pages reclaimed 137730 21148 27161 23455\nDirect reclaim write file async I/O 399 136 162 136\nDirect reclaim write anon async I/O 46977 2865 4686 3998\nDirect reclaim write file sync I/O 29 0 1 3\nDirect reclaim write anon sync I/O 31023 159 237 239\nWake kswapd requests 420 351 360 326\nKswapd wakeups 185 294 249 277\nKswapd pages scanned 15703488 16392500 17821724 17598737\nKswapd pages reclaimed 5808466 2908858 3139386 3145435\nKswapd reclaim write file async I/O 159938 18400 18717 13473\nKswapd reclaim write anon async I/O 3467554 228957 322799 234278\nKswapd reclaim write file sync I/O 0 0 0 0\nKswapd reclaim write anon sync I/O 0 0 0 0\nTime stalled direct reclaim (seconds) 9665.35 1707.81 2374.32 1871.23\nTime kswapd awake (seconds) 9401.21 1367.86 1951.75 1328.88\n\nTotal pages scanned 15926966 16434398 17873542 17644342\nTotal pages reclaimed 5946196 2930006 3166547 3168890\n%age total pages scanned/reclaimed 37.33% 17.83% 17.72% 17.96%\n%age total pages scanned/written 23.27% 1.52% 1.94% 1.43%\n%age file pages scanned/written 1.01% 0.11% 0.11% 0.08%\nPercentage Time Spent Direct Reclaim 44.55% 35.10% 41.42% 36.91%\nPercentage Time kswapd Awake 86.71% 43.58% 52.67% 41.14%\n\nWhile the scanning rates are slightly up, the scanned/reclaimed and\nscanned/written figures are much improved. The time spent in direct\nreclaim and with kswapd are massively reduced, mostly by the lowlumpy\npatches.\n\nFTrace Reclaim Statistics: congestion_wait\nDirect number congest waited 725 303 126 3\nDirect time congest waited 45524ms 9180ms 5936ms 300ms\nDirect full congest waited 487 190 52 3\nDirect number conditional waited 0 0 200 301\nDirect time conditional waited 0ms 0ms 0ms 1904ms\nDirect full conditional waited 0 0 0 19\nKSwapd number congest waited 0 2 23 4\nKSwapd time congest waited 0ms 200ms 420ms 404ms\nKSwapd full congest waited 0 2 2 4\nKSwapd number conditional waited 0 0 0 0\nKSwapd time conditional waited 0ms 0ms 0ms 0ms\nKSwapd full conditional waited 0 0 0 0\n\nNot as dramatic a story here but the time spent asleep is reduced and we\ncan still see what wait_iff_congested is going to sleep when necessary.\n\nMMTests Statistics: duration\nUser/Sys Time Running Test (seconds) 12028.09 3157.17 3357.79 3199.16\nTotal Elapsed Time (seconds) 10842.07 3138.72 3705.54 3229.85\n\nThe time to complete this test goes way down. With the full series, we\nare allocating over twice the number of huge pages in 30% of the time and\nthere is a corresponding impact on the allocation latency graph available\nat.\n\nhttp://www.csn.ul.ie/~mel/postings/vmscanreduce-20101509/highalloc-interlatency-powyah-mean.ps\n\nThis patch:\n\nAdd a trace event for shrink_inactive_list() and updates the sample\npostprocessing script appropriately. It can be used to determine how many\npages were reclaimed and for non-lumpy reclaim where exactly the pages\nwere reclaimed from.\n\nSigned-off-by: Mel Gorman \u003cmel@csn.ul.ie\u003e\nCc: Johannes Weiner \u003channes@cmpxchg.org\u003e\nCc: Minchan Kim \u003cminchan.kim@gmail.com\u003e\nCc: Wu Fengguang \u003cfengguang.wu@intel.com\u003e\nCc: KAMEZAWA Hiroyuki \u003ckamezawa.hiroyu@jp.fujitsu.com\u003e\nCc: KOSAKI Motohiro \u003ckosaki.motohiro@jp.fujitsu.com\u003e\nCc: Rik van Riel \u003criel@redhat.com\u003e\nSigned-off-by: Andrew Morton \u003cakpm@linux-foundation.org\u003e\nSigned-off-by: Linus Torvalds \u003ctorvalds@linux-foundation.org\u003e\n" }, { "commit": "b898cc70019ce1835bbf6c47bdf978adc36faa42", "tree": "9837f7a8677873eb44e25b841d4262cd474ee9f1", "parents": [ "755f0225e8347b23a33ee6e3fb14a35310f95766" ], "author": { "name": "Mel Gorman", "email": "mel@csn.ul.ie", "time": "Mon Aug 09 17:19:24 2010 -0700" }, "committer": { "name": "Linus Torvalds", "email": "torvalds@linux-foundation.org", "time": "Mon Aug 09 20:45:00 2010 -0700" }, "message": "vmscan: tracing: add a postprocessing script for reclaim-related ftrace events\n\nAdd a simple post-processing script for the reclaim-related trace events.\nIt can be used to give an indication of how much traffic there is on the\nLRU lists and how severe latencies due to reclaim are. Example output\nlooks like the following\n\nReclaim latencies expressed as order-latency_in_ms\nuname-3942 9-200.179000000004 9-98.7900000000373 9-99.8330000001006\nkswapd0-311 0-662.097999999998 0-2.79700000002049 \\\n\t0-149.100000000035 0-3295.73600000003 0-9806.31799999997 0-35528.833 \\\n\t0-10043.197 0-129740.979 0-3.50500000000466 0-3.54899999999907 \\\n\t0-9297.78999999992 0-3.48499999998603 0-3596.97999999998 0-3.92799999995623 \\\n\t0-3.35000000009313 0-16729.017 0-3.57799999997951 0-47435.0630000001 \\\n\t0-3.7819999998901 0-5864.06999999995 0-18635.334 0-10541.289 9-186011.565 \\\n\t9-3680.86300000001 9-1379.06499999994 9-958571.115 9-66215.474 \\\n\t9-6721.14699999988 9-1962.15299999993 9-1094806.125 9-2267.83199999994 \\\n\t9-47120.9029999999 9-427653.886 9-2.6359999999404 9-632.148999999976 \\\n\t9-476.753000000026 9-495.577000000048 9-8.45900000003166 9-6.6820000000298 \\\n\t9-1.30500000016764 9-251.746000000043 9-383.905000000028 9-80.1419999999925 \\\n\t9-281.160000000149 9-14.8780000000261 9-381.45299999998 9-512.07799999998 \\\n\t9-49.5519999999087 9-167.439000000013 9-183.820999999996 9-239.527999999933 \\\n\t9-19.9479999998584 9-148.747999999905 9-164.583000000101 9-16.9480000000913 \\\n\t9-192.376000000164 9-64.1010000000242 9-1.40800000005402 9-3.60800000000745 \\\n\t9-17.1359999999404 9-4.69500000006519 9-2.06400000001304 9-1582488.554 \\\n\t9-6244.19499999983 9-348153.812 9-2.0999999998603 9-0.987999999895692 \\\n\t0-32218.473 0-1.6140000000596 0-1.28100000019185 0-1.41300000017509 \\\n\t0-1.32299999985844 0-602.584000000032 0-1.34400000004098 0-1.6929999999702 \\\n\t1-22101.8190000001 9-174876.724 9-16.2420000000857 9-175.165999999736 \\\n\t9-15.8589999997057 9-0.604999999981374 9-3061.09000000032 9-479.277000000235 \\\n\t9-1.54499999992549 9-771.985000000335 9-4.88700000010431 9-15.0649999999441 \\\n\t9-0.879999999888241 9-252.01500000013 9-1381.03600000031 9-545.689999999944 \\\n\t9-3438.0129999998 9-3343.70099999988\nbench-stresshig-3942 9-7063.33900000004 9-129960.482 9-2062.27500000002 \\\n\t9-3845.59399999992 9-171.82799999998 9-16493.821 9-7615.23900000006 \\\n\t9-10217.848 9-983.138000000035 9-2698.39999999991 9-4016.1540000001 \\\n\t9-5522.37700000009 9-21630.429 \\\n\t9-15061.048 9-10327.953 9-542.69700000016 9-317.652000000002 \\\n\t9-8554.71699999995 9-1786.61599999992 9-1899.31499999994 9-2093.41899999999 \\\n\t9-4992.62400000007 9-942.648999999976 9-1923.98300000001 9-3.7980000001844 \\\n\t9-5.99899999983609 9-0.912000000011176 9-1603.67700000014 9-1.98300000000745 \\\n\t9-3.96500000008382 9-0.902999999932945 9-2802.72199999983 9-1078.24799999991 \\\n\t9-2155.82900000014 9-10.058999999892 9-1984.723 9-1687.97999999998 \\\n\t9-1136.05300000007 9-3183.61699999985 9-458.731000000145 9-6.48600000003353 \\\n\t9-1013.25200000009 9-8415.22799999989 9-10065.584 9-2076.79600000009 \\\n\t9-3792.65699999989 9-71.2010000001173 9-2560.96999999997 9-2260.68400000012 \\\n\t9-2862.65799999982 9-1255.81500000018 9-15.7440000001807 9-4.33499999996275 \\\n\t9-1446.63800000004 9-238.635000000009 9-60.1790000000037 9-4.38800000003539 \\\n\t9-639.567000000039 9-306.698000000091 9-31.4070000001229 9-74.997999999905 \\\n\t9-632.725999999791 9-1625.93200000003 9-931.266000000061 9-98.7749999999069 \\\n\t9-984.606999999844 9-225.638999999966 9-421.316000000108 9-653.744999999879 \\\n\t9-572.804000000004 9-769.158999999985 9-603.918000000063 9-4.28499999991618 \\\n\t9-626.21399999992 9-1721.25 9-0.854999999981374 9-572.39599999995 \\\n\t9-681.881999999983 9-1345.12599999993 9-363.666999999899 9-3823.31099999999 \\\n\t9-2991.28200000012 9-4.27099999994971 9-309.76500000013 9-3068.35700000008 \\\n\t9-788.25 9-3515.73999999999 9-2065.96100000013 9-286.719999999972 \\\n\t9-316.076000000117 9-344.151000000071 9-2.51000000000931 9-306.688000000082 \\\n\t9-1515.00099999993 9-336.528999999864 9-793.491999999853 9-457.348999999929 \\\n\t9-13620.155 9-119.933999999892 9-35.0670000000391 9-918.266999999993 \\\n\t9-828.569000000134 9-4863.81099999999 9-105.222000000067 9-894.23900000006 \\\n\t9-110.964999999851 9-0.662999999942258 9-12753.3150000002 9-12.6129999998957 \\\n\t9-13368.0899999999 9-12.4199999999255 9-1.00300000002608 9-1.41100000008009 \\\n\t9-10300.5290000001 9-16.502000000095 9-30.7949999999255 9-6283.0140000002 \\\n\t9-4320.53799999994 9-6826.27300000004 9-3.07299999985844 9-1497.26799999992 \\\n\t9-13.4040000000969 9-3.12999999988824 9-3.86100000003353 9-11.3539999998175 \\\n\t9-0.10799999977462 9-21.780999999959 9-209.695999999996 9-299.647000000114 \\\n\t9-6.01699999999255 9-20.8349999999627 9-22.5470000000205 9-5470.16800000006 \\\n\t9-7.60499999998137 9-0.821000000229105 9-1.56600000010803 9-14.1669999998994 \\\n\t9-0.209000000031665 9-1.82300000009127 9-1.70000000018626 9-19.9429999999702 \\\n\t9-124.266999999993 9-0.0389999998733401 9-6.71400000015274 9-16.7710000001825 \\\n\t9-31.0409999999683 9-0.516999999992549 9-115.888000000035 9-5.19900000002235 \\\n\t9-222.389999999898 9-11.2739999999758 9-80.9050000000279 9-8.14500000001863 \\\n\t9-4.44599999999627 9-0.218999999808148 9-0.715000000083819 9-0.233000000007451\n\\\n\t9-48.2630000000354 9-248.560999999987 9-374.96800000011 9-644.179000000004 \\\n\t9-0.835999999893829 9-79.0060000000522 9-128.447999999858 9-0.692000000039116 \\\n\t9-5.26500000013039 9-128.449000000022 9-2.04799999995157 9-12.0990000001621 \\\n\t9-8.39899999997579 9-10.3860000001732 9-11.9310000000987 9-53.4450000000652 \\\n\t9-0.46999999997206 9-2.96299999998882 9-17.9699999999721 9-0.776000000070781 \\\n\t9-25.2919999998994 9-33.1110000000335 9-0.434000000124797 9-0.641000000061467 \\\n\t9-0.505000000121072 9-1.12800000002608 9-149.222000000067 9-1.17599999997765 \\\n\t9-3247.33100000001 9-10.7439999999478 9-153.523000000045 9-1.38300000014715 \\\n\t9-794.762000000104 9-3.36199999996461 9-128.765999999829 9-181.543999999994 \\\n\t9-78149.8229999999 9-176.496999999974 9-89.9940000001807 9-9.12700000009499 \\\n\t9-250.827000000048 9-0.224999999860302 9-0.388999999966472 9-1.16700000036508 \\\n\t9-32.1740000001155 9-12.6800000001676 9-0.0720000001601875 9-0.274999999906868\n\\\n\t9-0.724000000394881 9-266.866000000387 9-45.5709999999963 9-4.54399999976158 \\\n\t9-8.27199999988079 9-4.38099999958649 9-0.512000000104308 9-0.0640000002458692\n\\\n\t9-5.20000000018626 9-0.0839999997988343 9-12.816000000108 9-0.503000000026077 \\\n\t9-0.507999999914318 9-6.23999999975786 9-3.35100000025705 9-18.8530000001192 \\\n\t9-25.2220000000671 9-68.2309999996796 9-98.9939999999478 9-0.441000000108033 \\\n\t9-4.24599999981001 9-261.702000000048 9-3.01599999982864 9-0.0749999997206032 \\\n\t9-0.0370000000111759 9-4.375 9-3.21800000034273 9-11.3960000001825 \\\n\t9-0.0540000000037253 9-0.286000000312924 9-0.865999999921769 \\\n\t9-0.294999999925494 9-6.45999999996275 9-4.31099999975413 9-128.248999999836 \\\n\t9-0.282999999821186 9-102.155000000261 9-0.0860000001266599 \\\n\t9-0.0540000000037253 9-0.935000000055879 9-0.0670000002719462 \\\n\t9-5.8640000000596 9-19.9860000000335 9-4.18699999991804 9-0.566000000108033 \\\n\t9-2.55099999997765 9-0.702000000048429 9-131.653999999631 9-0.638999999966472 \\\n\t9-14.3229999998584 9-183.398000000045 9-178.095999999903 9-3.22899999981746 \\\n\t9-7.31399999978021 9-22.2400000002235 9-11.7979999999516 9-108.10599999968 \\\n\t9-99.0159999998286 9-102.640999999829 9-38.414000000339\nProcess Direct Wokeup Pages Pages Pages\ndetails Rclms Kswapd Scanned Sync-IO ASync-IO\ncc1-30800 0 1 0 0 0 wakeup-0\u003d1\ncc1-24260 0 1 0 0 0 wakeup-0\u003d1\ncc1-24152 0 12 0 0 0 wakeup-0\u003d12\ncc1-8139 0 1 0 0 0 wakeup-0\u003d1\ncc1-4390 0 1 0 0 0 wakeup-0\u003d1\ncc1-4648 0 7 0 0 0 wakeup-0\u003d7\ncc1-4552 0 3 0 0 0 wakeup-0\u003d3\ndd-4550 0 31 0 0 0 wakeup-0\u003d31\ndate-4898 0 1 0 0 0 wakeup-0\u003d1\ncc1-6549 0 7 0 0 0 wakeup-0\u003d7\nas-22202 0 17 0 0 0 wakeup-0\u003d17\ncc1-6495 0 9 0 0 0 wakeup-0\u003d9\ncc1-8299 0 1 0 0 0 wakeup-0\u003d1\ncc1-6009 0 1 0 0 0 wakeup-0\u003d1\ncc1-2574 0 2 0 0 0 wakeup-0\u003d2\ncc1-30568 0 1 0 0 0 wakeup-0\u003d1\ncc1-2679 0 6 0 0 0 wakeup-0\u003d6\nsh-13747 0 12 0 0 0 wakeup-0\u003d12\ncc1-22193 0 18 0 0 0 wakeup-0\u003d18\ncc1-30725 0 2 0 0 0 wakeup-0\u003d2\nas-4392 0 2 0 0 0 wakeup-0\u003d2\ncc1-28180 0 14 0 0 0 wakeup-0\u003d14\ncc1-13697 0 2 0 0 0 wakeup-0\u003d2\ncc1-22207 0 8 0 0 0 wakeup-0\u003d8\ncc1-15270 0 179 0 0 0 wakeup-0\u003d179\ncc1-22011 0 82 0 0 0 wakeup-0\u003d82\ncp-14682 0 1 0 0 0 wakeup-0\u003d1\nas-11926 0 2 0 0 0 wakeup-0\u003d2\ncc1-6016 0 5 0 0 0 wakeup-0\u003d5\nmake-18554 0 13 0 0 0 wakeup-0\u003d13\ncc1-8292 0 12 0 0 0 wakeup-0\u003d12\nmake-24381 0 1 0 0 0 wakeup-1\u003d1\ndate-18681 0 33 0 0 0 wakeup-0\u003d33\ncc1-32276 0 1 0 0 0 wakeup-0\u003d1\ntimestamp-outpu-2809 0 253 0 0 0 wakeup-0\u003d240 wakeup-1\u003d13\ndate-18624 0 7 0 0 0 wakeup-0\u003d7\ncc1-30960 0 9 0 0 0 wakeup-0\u003d9\ncc1-4014 0 1 0 0 0 wakeup-0\u003d1\ncc1-30706 0 22 0 0 0 wakeup-0\u003d22\nuname-3942 4 1 306 0 17 direct-9\u003d4 wakeup-9\u003d1\ncc1-28207 0 1 0 0 0 wakeup-0\u003d1\ncc1-30563 0 9 0 0 0 wakeup-0\u003d9\ncc1-22214 0 10 0 0 0 wakeup-0\u003d10\ncc1-28221 0 11 0 0 0 wakeup-0\u003d11\ncc1-28123 0 6 0 0 0 wakeup-0\u003d6\nkswapd0-311 0 7 357302 0 34233 wakeup-0\u003d7\ncc1-5988 0 7 0 0 0 wakeup-0\u003d7\nas-30734 0 161 0 0 0 wakeup-0\u003d161\ncc1-22004 0 45 0 0 0 wakeup-0\u003d45\ndate-4590 0 4 0 0 0 wakeup-0\u003d4\ncc1-15279 0 213 0 0 0 wakeup-0\u003d213\ndate-30735 0 1 0 0 0 wakeup-0\u003d1\ncc1-30583 0 4 0 0 0 wakeup-0\u003d4\ncc1-32324 0 2 0 0 0 wakeup-0\u003d2\ncc1-23933 0 3 0 0 0 wakeup-0\u003d3\ncc1-22001 0 36 0 0 0 wakeup-0\u003d36\nbench-stresshig-3942 287 287 80186 6295 12196 direct-9\u003d287 wakeup-9\u003d287\ncc1-28170 0 7 0 0 0 wakeup-0\u003d7\ndate-7932 0 92 0 0 0 wakeup-0\u003d92\ncc1-22222 0 6 0 0 0 wakeup-0\u003d6\ncc1-32334 0 16 0 0 0 wakeup-0\u003d16\ncc1-2690 0 6 0 0 0 wakeup-0\u003d6\ncc1-30733 0 9 0 0 0 wakeup-0\u003d9\ncc1-32298 0 2 0 0 0 wakeup-0\u003d2\ncc1-13743 0 18 0 0 0 wakeup-0\u003d18\ncc1-22186 0 4 0 0 0 wakeup-0\u003d4\ncc1-28214 0 11 0 0 0 wakeup-0\u003d11\ncc1-13735 0 1 0 0 0 wakeup-0\u003d1\nupdatedb-8173 0 18 0 0 0 wakeup-0\u003d18\ncc1-13750 0 3 0 0 0 wakeup-0\u003d3\ncat-2808 0 2 0 0 0 wakeup-0\u003d2\ncc1-15277 0 169 0 0 0 wakeup-0\u003d169\ndate-18317 0 1 0 0 0 wakeup-0\u003d1\ncc1-15274 0 197 0 0 0 wakeup-0\u003d197\ncc1-30732 0 1 0 0 0 wakeup-0\u003d1\n\nKswapd Kswapd Order Pages Pages Pages\nInstance Wakeups Re-wakeup Scanned Sync-IO ASync-IO\nkswapd0-311 91 24 357302 0 34233 wake-0\u003d31 wake-1\u003d1 wake-9\u003d59 rewake-0\u003d10 rewake-1\u003d1 rewake-9\u003d13\n\nSummary\nDirect reclaims: \t\t291\nDirect reclaim pages scanned:\t437794\nDirect reclaim write sync I/O:\t6295\nDirect reclaim write async I/O:\t46446\nWake kswapd requests:\t\t2152\nTime stalled direct reclaim: \t519.163009000002 ms\n\nKswapd wakeups:\t\t\t91\nKswapd pages scanned:\t\t357302\nKswapd reclaim write sync I/O:\t0\nKswapd reclaim write async I/O:\t34233\nTime kswapd awake:\t\t5282.749757 ms\n\nSigned-off-by: Mel Gorman \u003cmel@csn.ul.ie\u003e\nAcked-by: Rik van Riel \u003criel@redhat.com\u003e\nAcked-by: Larry Woodman \u003clwoodman@redhat.com\u003e\nCc: Dave Chinner \u003cdavid@fromorbit.com\u003e\nCc: Chris Mason \u003cchris.mason@oracle.com\u003e\nCc: Nick Piggin \u003cnpiggin@suse.de\u003e\nCc: Rik van Riel \u003criel@redhat.com\u003e\nCc: Johannes Weiner \u003channes@cmpxchg.org\u003e\nCc: Christoph Hellwig \u003chch@infradead.org\u003e\nCc: KAMEZAWA Hiroyuki \u003ckamezawa.hiroyu@jp.fujitsu.com\u003e\nCc: KOSAKI Motohiro \u003ckosaki.motohiro@jp.fujitsu.com\u003e\nCc: Andrea Arcangeli \u003caarcange@redhat.com\u003e\nCc: Michael Rubin \u003cmrubin@google.com\u003e\nSigned-off-by: Andrew Morton \u003cakpm@linux-foundation.org\u003e\nSigned-off-by: Linus Torvalds \u003ctorvalds@linux-foundation.org\u003e\n" }, { "commit": "c9d05cfc001fef3d6d37651e19ab9227a32b71f5", "tree": "ac5f54c9fcf8336c7787fca63875b18621ee3fd1", "parents": [ "0d3d062a6e289e065bd0aa537a6806a1806bf8aa" ], "author": { "name": "Mel Gorman", "email": "mel@csn.ul.ie", "time": "Mon Sep 21 17:02:47 2009 -0700" }, "committer": { "name": "Linus Torvalds", "email": "torvalds@linux-foundation.org", "time": "Tue Sep 22 07:17:34 2009 -0700" }, "message": "tracing, page-allocator: add a postprocessing script for page-allocator-related ftrace events\n\nThis patch adds a simple post-processing script for the\npage-allocator-related trace events. It can be used to give an indication\nof who the most allocator-intensive processes are and how often the zone\nlock was taken during the tracing period. Example output looks like\n\nProcess Pages Pages Pages Pages PCPU PCPU PCPU Fragment Fragment MigType Fragment Fragment Unknown\ndetails allocd allocd freed freed pages drains refills Fallback Causing Changed Severe Moderate\n under lock direct pagevec drain\nswapper-0 0 0 2 0 0 0 0 0 0 0 0 0 0\nXorg-3770 10603 5952 3685 6978 5996 194 192 0 0 0 0 0 0\nmodprobe-21397 51 0 0 86 31 1 0 0 0 0 0 0 0\nxchat-5370 228 93 0 0 0 0 3 0 0 0 0 0 0\nawesome-4317 32 32 0 0 0 0 32 0 0 0 0 0 0\nthinkfan-3863 2 0 1 1 0 0 0 0 0 0 0 0 0\nhald-addon-stor-3935 2 0 0 0 0 0 0 0 0 0 0 0 0\nakregator-4506 1 1 0 0 0 0 1 0 0 0 0 0 0\nxmms-14888 0 0 1 0 0 0 0 0 0 0 0 0 0\nkhelper-12 1 0 0 0 0 0 0 0 0 0 0 0 0\n\nOptionally, the output can include information on the parent or aggregate\nbased on process name instead of aggregating based on each pid. Example output\nincluding parent information and stripped out the PID looks something like;\n\nProcess Pages Pages Pages Pages PCPU PCPU PCPU Fragment Fragment MigType Fragment Fragment Unknown\ndetails allocd allocd freed freed pages drains refills Fallback Causing Changed Severe Moderate\n under lock direct pagevec drain\ngdm-3756 :: Xorg-3770 3796 2976 99 3813 3224 104 98 0 0 0 0 0 0\ninit-1 :: hald-3892 1 0 0 0 0 0 0 0 0 0 0 0 0\ngit-21447 :: editor-21448 4 0 4 0 0 0 0 0 0 0 0 0 0\n\nThis says that Xorg allocated 3796 pages and it\u0027s parent process is gdm\nwith a PID of 3756;\n\nThe postprocessor parses the text output of tracing. While there is a\nbinary format, the expectation is that the binary output can be readily\ntranslated into text and post-processed offline. Obviously if the text\nformat changes, the parser will break but the regular expression parser is\nfairly rudimentary so should be readily adjustable.\n\nSigned-off-by: Mel Gorman \u003cmel@csn.ul.ie\u003e\nCc: Rik van Riel \u003criel@redhat.com\u003e\nReviewed-by: Ingo Molnar \u003cmingo@elte.hu\u003e\nCc: Larry Woodman \u003clwoodman@redhat.com\u003e\nCc: Peter Zijlstra \u003cpeterz@infradead.org\u003e\nCc: Li Ming Chun \u003cmacli@brc.ubc.ca\u003e\nSigned-off-by: Andrew Morton \u003cakpm@linux-foundation.org\u003e\nSigned-off-by: Linus Torvalds \u003ctorvalds@linux-foundation.org\u003e\n" } ] }