pauldoo opened a new pull request, #16804: URL: https://github.com/apache/lucene/pull/16804
The MemorySegmentIndexInput prefetch logic contains a heuristic to issue madvise calls only when it believes the data is likely to not be resident. We observed that after a long run of checks reporting data being loaded, the system fails to react quickly if data is then evicted. This results in an extended period of low IO rate while the system is major faulting on every read. This PR sets an upper limit on the interval between residency checks. Large enough that the cost of the check is amortized, small enough that the system reacts quickly. ## Benchmark Single thread, 20G of data, 4K random reads, prefetching 64 reads in advance, 64G of ram, local NVMe drive. At 60s into the run after the data is fully resident, I use cgroup `memory.reclaim` to reclaim the memory. The reclaim itself takes around 4s to execute. ### Before ``` t= 57s 2,615,806 IOPS counter 86,334,997 t= 58s 2,620,921 IOPS counter 88,957,022 t= 59s 2,626,820 IOPS counter 91,585,111 t= 60s 2,631,145 IOPS counter 94,217,222 t= 61s 760,786 IOPS counter 94,978,280 t= 62s 27,990 IOPS counter 95,005,863 t= 63s 7,984 IOPS counter 95,014,044 t= 64s 4,997 IOPS counter 95,018,955 t= 65s 1,998 IOPS counter 95,021,307 t= 66s 2,997 IOPS counter 95,023,570 t= 67s 1,998 IOPS counter 95,025,915 t= 68s 2,998 IOPS counter 95,028,679 t= 69s 1,998 IOPS counter 95,031,314 t= 70s 3,999 IOPS counter 95,034,440 t= 71s 2,998 IOPS counter 95,037,640 t= 72s 2,998 IOPS counter 95,041,068 t= 73s 3,998 IOPS counter 95,044,932 t= 74s 3,998 IOPS counter 95,049,018 t= 75s 4,999 IOPS counter 95,053,717 t= 76s 4,997 IOPS counter 95,058,581 ``` ### After ``` t= 57s 2,628,565 IOPS counter 1,384 t= 58s 2,643,455 IOPS counter 1,970 t= 59s 2,646,455 IOPS counter 1,913 t= 60s 2,656,072 IOPS counter 1,645 t= 61s 766,668 IOPS counter 1,488 t= 62s 31,984 IOPS counter 233 t= 63s 11,973 IOPS counter 405 t= 64s 41,976 IOPS counter 0 t= 65s 107,922 IOPS counter 1 t= 66s 99,944 IOPS counter 0 t= 67s 74,968 IOPS counter 0 t= 68s 51,970 IOPS counter 121 t= 69s 36,973 IOPS counter 0 t= 70s 19,991 IOPS counter 1 t= 71s 13,991 IOPS counter 1 t= 72s 14,994 IOPS counter 434 t= 73s 9,996 IOPS counter 0 t= 74s 9,995 IOPS counter 279 t= 75s 9,993 IOPS counter 1,814 t= 76s 13,994 IOPS counter 1,880 ``` Note that after the reclaim the read rate is now significantly higher than before. The logged counter value shows the heuristic reacting. IO rate does dip approx 10s into recovery, this is related to a separate issue described below. ## Not fixed _This is a separate issue I will attempt to fix in a followup PR._ When the data is mostly warm (> 80% resident) the heuristic often encounters runs of checks that all report resident. This is enough for the heuristic to begin to back off from making madvise calls while there is still a meaningful number of reads for data that isn't yet resident. This results in an increased rate of major faults which reduces performance. This is demonstrated in the warmup part of the benchmark, which is unaffected by this change and still looks like the numbers below. It also appears in the recovery phase with this PR applied. Logs from the benchmark warmup are below. Note the first few seconds which issue madvise and achieve good IOPS from disk, the rate then drops when the heuristic prematurely stops issuing madvise calls. I am exploring fixes for this, but I so far haven't found a heuristic that works well across NORMAL and RANDOM madvise modes. So for now this PR includes only a fix to cap the interval between checks. ``` t= 1s 123,959 IOPS counter 0 t= 2s 179,525 IOPS counter 0 t= 3s 178,913 IOPS counter 0 t= 4s 176,928 IOPS counter 1 t= 5s 161,880 IOPS counter 0 t= 6s 144,838 IOPS counter 2 t= 7s 82,942 IOPS counter 0 t= 8s 67,932 IOPS counter 0 t= 9s 38,962 IOPS counter 2 t= 10s 21,980 IOPS counter 215 t= 11s 14,988 IOPS counter 385 t= 12s 9,993 IOPS counter 2,932 t= 13s 9,990 IOPS counter 253 t= 14s 12,988 IOPS counter 7,897 t= 15s 12,986 IOPS counter 21,268 t= 16s 15,985 IOPS counter 4,118 t= 17s 20,958 IOPS counter 9,308 t= 18s 32,975 IOPS counter 42,282 t= 19s 42,952 IOPS counter 84,483 t= 20s 68,943 IOPS counter 153,630 t= 21s 122,851 IOPS counter 276,410 t= 22s 224,750 IOPS counter 502,002 t= 23s 496,428 IOPS counter 998,781 t= 24s 928,009 IOPS counter 1,927,836 t= 25s 1,699,728 IOPS counter 3,630,314 ``` -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
