Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Reduce memory overhead in the cht #79

Merged
merged 1 commit into from
Feb 1, 2022
Merged

Reduce memory overhead in the cht #79

merged 1 commit into from
Feb 1, 2022

Conversation

tatsuya6502
Copy link
Member

  • Perform GC-only rehashing to remove tombstones.
  • Shrink capacity when possible.

Relates to #72.

@tatsuya6502
Reduce memory overhead in the cht
80d5a87 
- Perform GC-only rehashing to remove tombstones.
- Shrink capacity when possible.

Relates to #72.
@tatsuya6502 tatsuya6502 self-assigned this Feb 1, 2022
@tatsuya6502 tatsuya6502 added the enhancement New feature or request label Feb 1, 2022
@tatsuya6502 tatsuya6502 added this to the v0.7.2 milestone Feb 1, 2022
tatsuya6502
tatsuya6502 commented Feb 1, 2022
View reviewed changes
Copy link
Member Author

@tatsuya6502 tatsuya6502 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Merging. Will tune the performance parameters later.

@tatsuya6502 tatsuya6502 merged commit 09b3f31 into master Feb 1, 2022
@tatsuya6502 tatsuya6502 deleted the manage-tombstones branch February 1, 2022 10:58
tatsuya6502 added a commit that referenced this pull request Feb 2, 2022
@tatsuya6502
Tweak the GC trigger for the cht
57b2aa5 
Relates to #79.
@tatsuya6502 tatsuya6502 mentioned this pull request Feb 5, 2022
Merged
@texascloud
Copy link

Hello! I have come to you after much debugging. I don't know why, but the logic gated by this code causes .run_pending_tasks() to occasionally take significantly longer, especially if the number of entries which are being evicted is in the range of millions, but it presents at values significantly lower than that too.

if tbc >= 25_000.0 || tbc / real_cap >= 0.1

If I change the 0.1 to 0.5, I get results like this:

0215 00:20:22.976972  INFO [serial] inserting 5000000 items
0215 00:20:32.243169  INFO done after 9266ms - size: 4999936
0215 00:20:32.243266  INFO [before sync] size: 5000000
0215 00:20:39.282989  INFO [polling till empty] num_during_iter: 5000000 - removed: cycle/60001 total/60001 - elapsed_ms: 38 - items/ms: 1578
0215 00:20:43.281050  INFO [polling till empty] num_during_iter: 4939999 - removed: cycle/60002 total/120003 - elapsed_ms: 36 - items/ms: 1666
0215 00:20:44.280029  INFO [polling till empty] num_during_iter: 4879997 - removed: cycle/60002 total/180005 - elapsed_ms: 35 - items/ms: 1714
0215 00:20:47.279363  INFO [polling till empty] num_during_iter: 4819995 - removed: cycle/60002 total/240007 - elapsed_ms: 34 - items/ms: 1764
0215 00:20:50.280655  INFO [polling till empty] num_during_iter: 4759993 - removed: cycle/60002 total/300009 - elapsed_ms: 36 - items/ms: 1666
0215 00:20:52.283514  INFO [polling till empty] num_during_iter: 4699991 - removed: cycle/60002 total/360011 - elapsed_ms: 39 - items/ms: 1538
0215 00:20:55.279434  INFO [polling till empty] num_during_iter: 4639989 - removed: cycle/60002 total/420013 - elapsed_ms: 35 - items/ms: 1714
0215 00:20:57.284198  INFO [polling till empty] num_during_iter: 4579987 - removed: cycle/60002 total/480015 - elapsed_ms: 38 - items/ms: 1579
0215 00:21:00.284056  INFO [polling till empty] num_during_iter: 4519985 - removed: cycle/60002 total/540017 - elapsed_ms: 39 - items/ms: 1538
0215 00:21:03.286988  INFO [polling till empty] num_during_iter: 4459983 - removed: cycle/60002 total/600019 - elapsed_ms: 42 - items/ms: 1428
0215 00:21:05.283812  INFO [polling till empty] num_during_iter: 4399981 - removed: cycle/60002 total/660021 - elapsed_ms: 38 - items/ms: 1579
0215 00:21:08.282565  INFO [polling till empty] num_during_iter: 4339979 - removed: cycle/60002 total/720023 - elapsed_ms: 38 - items/ms: 1579
0215 00:21:10.257832  INFO [polling till empty] num_during_iter: 4279977 - removed: cycle/18143 total/738166 - elapsed_ms: 13 - items/ms: 1395
0215 00:21:12.271668  INFO [polling till empty] num_during_iter: 4261834 - removed: cycle/41859 total/780025 - elapsed_ms: 27 - items/ms: 1550
0215 00:21:13.284663  INFO [polling till empty] num_during_iter: 4219975 - removed: cycle/60002 total/840027 - elapsed_ms: 39 - items/ms: 1538
0215 00:21:16.284791  INFO [polling till empty] num_during_iter: 4159973 - removed: cycle/60002 total/900029 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:18.282902  INFO [polling till empty] num_during_iter: 4099971 - removed: cycle/60002 total/960031 - elapsed_ms: 38 - items/ms: 1579
0215 00:21:21.285095  INFO [polling till empty] num_during_iter: 4039969 - removed: cycle/60002 total/1020033 - elapsed_ms: 39 - items/ms: 1538
0215 00:21:23.270587  INFO [polling till empty] num_during_iter: 3979967 - removed: cycle/37073 total/1057106 - elapsed_ms: 26 - items/ms: 1425
0215 00:21:24.259405  INFO [polling till empty] num_during_iter: 3942894 - removed: cycle/22929 total/1080035 - elapsed_ms: 15 - items/ms: 1528
0215 00:21:26.285166  INFO [polling till empty] num_during_iter: 3919965 - removed: cycle/60002 total/1140037 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:29.284835  INFO [polling till empty] num_during_iter: 3859963 - removed: cycle/60002 total/1200039 - elapsed_ms: 39 - items/ms: 1538
0215 00:21:31.284801  INFO [polling till empty] num_during_iter: 3799961 - removed: cycle/60002 total/1260041 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:34.284702  INFO [polling till empty] num_during_iter: 3739959 - removed: cycle/60002 total/1320043 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:36.284188  INFO [polling till empty] num_during_iter: 3679957 - removed: cycle/60002 total/1380045 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:39.285984  INFO [polling till empty] num_during_iter: 3619955 - removed: cycle/60002 total/1440047 - elapsed_ms: 41 - items/ms: 1463
0215 00:21:42.284987  INFO [polling till empty] num_during_iter: 3559953 - removed: cycle/60002 total/1500049 - elapsed_ms: 40 - items/ms: 1500
0215 00:21:45.286834  INFO [polling till empty] num_during_iter: 3499951 - removed: cycle/60002 total/1560051 - elapsed_ms: 41 - items/ms: 1463
inner loop longer now 55ms
inner loop longer now 53ms
inner loop longer now 53ms
inner loop longer now 53ms
inner loop longer now 58ms
inner loop longer now 57ms
inner loop longer now 60ms
inner loop longer now 65ms
inner loop longer now 59ms
inner loop longer now 61ms
inner loop longer now 61ms
inner loop longer now 57ms
inner loop longer now 60ms
inner loop longer now 58ms
inner loop longer now 53ms
inner loop longer now 52ms
inner loop longer now 51ms
inner loop longer now 50ms
inner loop longer now 55ms
inner loop longer now 59ms
inner loop longer now 59ms
inner loop longer now 62ms
inner loop longer now 61ms
inner loop longer now 60ms
inner loop longer now 57ms
inner loop longer now 55ms
inner loop longer now 58ms
inner loop longer now 59ms
inner loop longer now 55ms
inner loop longer now 53ms
inner loop longer now 47ms
inner loop longer now 45ms
inner loop longer now 47ms
inner loop longer now 57ms
inner loop longer now 63ms
inner loop longer now 58ms
inner loop longer now 52ms
inner loop longer now 54ms
inner loop longer now 61ms
inner loop longer now 58ms
inner loop longer now 56ms
inner loop longer now 57ms
inner loop longer now 63ms
inner loop longer now 60ms
inner loop longer now 64ms
inner loop longer now 64ms
inner loop longer now 62ms
inner loop longer now 55ms
inner loop longer now 59ms
inner loop longer now 60ms
inner loop longer now 57ms
inner loop longer now 57ms
inner loop longer now 58ms
inner loop longer now 49ms
inner loop longer now 55ms
inner loop longer now 51ms
inner loop longer now 49ms
inner loop longer now 52ms
inner loop longer now 47ms
inner loop longer now 60ms
inner loop longer now 57ms
inner loop longer now 60ms
other work in expiring entries took 3648
0215 00:21:50.899043  INFO [polling till empty] num_during_iter: 3439949 - removed: cycle/60002 total/1620053 - elapsed_ms: 3654 - items/ms: 16
inner loop longer now 58ms
inner loop longer now 60ms
0215 00:21:51.149464  INFO [polling till empty] num_during_iter: 3379947 - removed: cycle/60002 total/1680055 - elapsed_ms: 250 - items/ms: 240
0215 00:21:52.343265  INFO [polling till empty] num_during_iter: 3319945 - removed: cycle/46274 total/1726329 - elapsed_ms: 98 - items/ms: 472
0215 00:21:53.277026  INFO [polling till empty] num_during_iter: 3273671 - removed: cycle/13728 total/1740057 - elapsed_ms: 32 - items/ms: 429
0215 00:21:55.373140  INFO [polling till empty] num_during_iter: 3259943 - removed: cycle/60002 total/1800059 - elapsed_ms: 128 - items/ms: 468
0215 00:21:58.378099  INFO [polling till empty] num_during_iter: 3199941 - removed: cycle/60002 total/1860061 - elapsed_ms: 133 - items/ms: 451
0215 00:22:00.374099  INFO [polling till empty] num_during_iter: 3139939 - removed: cycle/60002 total/1920063 - elapsed_ms: 129 - items/ms: 465
0215 00:22:03.373482  INFO [polling till empty] num_during_iter: 3079937 - removed: cycle/60002 total/1980065 - elapsed_ms: 129 - items/ms: 465
0215 00:22:05.311049  INFO [polling till empty] num_during_iter: 3019935 - removed: cycle/60002 total/2040067 - elapsed_ms: 66 - items/ms: 909
0215 00:22:08.307935  INFO [polling till empty] num_during_iter: 2959933 - removed: cycle/60002 total/2100069 - elapsed_ms: 63 - items/ms: 952
0215 00:22:11.283043  INFO [polling till empty] num_during_iter: 2899931 - removed: cycle/60002 total/2160071 - elapsed_ms: 38 - items/ms: 1579
0215 00:22:13.283127  INFO [polling till empty] num_during_iter: 2839929 - removed: cycle/60002 total/2220073 - elapsed_ms: 38 - items/ms: 1579
0215 00:22:16.283067  INFO [polling till empty] num_during_iter: 2779927 - removed: cycle/60002 total/2280075 - elapsed_ms: 38 - items/ms: 1579
0215 00:22:18.282396  INFO [polling till empty] num_during_iter: 2719925 - removed: cycle/60002 total/2340077 - elapsed_ms: 37 - items/ms: 1621
0215 00:22:21.282380  INFO [polling till empty] num_during_iter: 2659923 - removed: cycle/60002 total/2400079 - elapsed_ms: 38 - items/ms: 1579
0215 00:22:23.270550  INFO [polling till empty] num_during_iter: 2599921 - removed: cycle/39493 total/2439572 - elapsed_ms: 26 - items/ms: 1518
0215 00:22:25.257015  INFO [polling till empty] num_during_iter: 2560428 - removed: cycle/20509 total/2460081 - elapsed_ms: 12 - items/ms: 1709
0215 00:22:26.281062  INFO [polling till empty] num_during_iter: 2539919 - removed: cycle/60002 total/2520083 - elapsed_ms: 36 - items/ms: 1666
0215 00:22:29.286712  INFO [polling till empty] num_during_iter: 2479917 - removed: cycle/60002 total/2580085 - elapsed_ms: 42 - items/ms: 1428
0215 00:22:31.284630  INFO [polling till empty] num_during_iter: 2419915 - removed: cycle/60002 total/2640087 - elapsed_ms: 39 - items/ms: 1538
0215 00:22:34.284504  INFO [polling till empty] num_during_iter: 2359913 - removed: cycle/60002 total/2700089 - elapsed_ms: 40 - items/ms: 1500
0215 00:22:36.284147  INFO [polling till empty] num_during_iter: 2299911 - removed: cycle/60002 total/2760091 - elapsed_ms: 39 - items/ms: 1538
0215 00:22:39.285287  INFO [polling till empty] num_during_iter: 2239909 - removed: cycle/60002 total/2820093 - elapsed_ms: 40 - items/ms: 1500
0215 00:22:42.284914  INFO [polling till empty] num_during_iter: 2179907 - removed: cycle/60002 total/2880095 - elapsed_ms: 40 - items/ms: 1500
0215 00:22:44.275285  INFO [polling till empty] num_during_iter: 2119905 - removed: cycle/44856 total/2924951 - elapsed_ms: 31 - items/ms: 1446
0215 00:22:45.255715  INFO [polling till empty] num_during_iter: 2075049 - removed: cycle/15146 total/2940097 - elapsed_ms: 11 - items/ms: 1376
0215 00:22:48.293616  INFO [polling till empty] num_during_iter: 2059903 - removed: cycle/60002 total/3000099 - elapsed_ms: 49 - items/ms: 1224
0215 00:22:51.292952  INFO [polling till empty] num_during_iter: 1999901 - removed: cycle/60002 total/3060101 - elapsed_ms: 48 - items/ms: 1250
0215 00:22:54.287375  INFO [polling till empty] num_during_iter: 1939899 - removed: cycle/60002 total/3120103 - elapsed_ms: 43 - items/ms: 1395
inner loop longer now 24ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 24ms
inner loop longer now 24ms
0215 00:22:56.424655  INFO [polling till empty] num_during_iter: 1879897 - removed: cycle/60002 total/3180105 - elapsed_ms: 179 - items/ms: 335
inner loop longer now 24ms
inner loop longer now 25ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 24ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 21ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 24ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 24ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 24ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
inner loop longer now 23ms
inner loop longer now 23ms
inner loop longer now 22ms
other work in expiring entries took 1461
0215 00:22:59.711709  INFO [polling till empty] num_during_iter: 1819895 - removed: cycle/60002 total/3240107 - elapsed_ms: 1467 - items/ms: 40
inner loop longer now 25ms
inner loop longer now 23ms
0215 00:23:01.420114  INFO [polling till empty] num_during_iter: 1759893 - removed: cycle/60002 total/3300109 - elapsed_ms: 175 - items/ms: 342
0215 00:23:03.280751  INFO [polling till empty] num_during_iter: 1699891 - removed: cycle/16633 total/3316742 - elapsed_ms: 36 - items/ms: 462
0215 00:23:04.334370  INFO [polling till empty] num_during_iter: 1683258 - removed: cycle/43369 total/3360111 - elapsed_ms: 89 - items/ms: 487
0215 00:23:06.374591  INFO [polling till empty] num_during_iter: 1639889 - removed: cycle/60002 total/3420113 - elapsed_ms: 130 - items/ms: 461
0215 00:23:09.370134  INFO [polling till empty] num_during_iter: 1579887 - removed: cycle/60002 total/3480115 - elapsed_ms: 125 - items/ms: 480
0215 00:23:11.369464  INFO [polling till empty] num_during_iter: 1519885 - removed: cycle/60002 total/3540117 - elapsed_ms: 125 - items/ms: 480
0215 00:23:14.351265  INFO [polling till empty] num_during_iter: 1459883 - removed: cycle/60002 total/3600119 - elapsed_ms: 106 - items/ms: 566
0215 00:23:16.311857  INFO [polling till empty] num_during_iter: 1399881 - removed: cycle/60002 total/3660121 - elapsed_ms: 67 - items/ms: 895
0215 00:23:19.302834  INFO [polling till empty] num_during_iter: 1339879 - removed: cycle/60002 total/3720123 - elapsed_ms: 58 - items/ms: 1034
0215 00:23:23.287930  INFO [polling till empty] num_during_iter: 1279877 - removed: cycle/60002 total/3780125 - elapsed_ms: 43 - items/ms: 1395
0215 00:23:24.286809  INFO [polling till empty] num_during_iter: 1219875 - removed: cycle/60002 total/3840127 - elapsed_ms: 42 - items/ms: 1428
0215 00:23:27.289109  INFO [polling till empty] num_during_iter: 1159873 - removed: cycle/60002 total/3900129 - elapsed_ms: 45 - items/ms: 1333
0215 00:23:29.289941  INFO [polling till empty] num_during_iter: 1099871 - removed: cycle/60002 total/3960131 - elapsed_ms: 44 - items/ms: 1363
0215 00:23:32.289917  INFO [polling till empty] num_during_iter: 1039869 - removed: cycle/60002 total/4020133 - elapsed_ms: 45 - items/ms: 1333
0215 00:23:35.287222  INFO [polling till empty] num_during_iter: 979867 - removed: cycle/60002 total/4080135 - elapsed_ms: 42 - items/ms: 1428
0215 00:23:37.285451  INFO [polling till empty] num_during_iter: 919865 - removed: cycle/60002 total/4140137 - elapsed_ms: 40 - items/ms: 1500
0215 00:23:40.289295  INFO [polling till empty] num_during_iter: 859863 - removed: cycle/60002 total/4200139 - elapsed_ms: 45 - items/ms: 1333
0215 00:23:42.288687  INFO [polling till empty] num_during_iter: 799861 - removed: cycle/60002 total/4260141 - elapsed_ms: 44 - items/ms: 1363
0215 00:23:45.288637  INFO [polling till empty] num_during_iter: 739859 - removed: cycle/60002 total/4320143 - elapsed_ms: 44 - items/ms: 1363
0215 00:23:47.272691  INFO [polling till empty] num_during_iter: 679857 - removed: cycle/38326 total/4358469 - elapsed_ms: 28 - items/ms: 1368
0215 00:23:48.261891  INFO [polling till empty] num_during_iter: 641531 - removed: cycle/21676 total/4380145 - elapsed_ms: 17 - items/ms: 1275
0215 00:23:50.288112  INFO [polling till empty] num_during_iter: 619855 - removed: cycle/60002 total/4440147 - elapsed_ms: 43 - items/ms: 1395
0215 00:23:53.290423  INFO [polling till empty] num_during_iter: 559853 - removed: cycle/60002 total/4500149 - elapsed_ms: 44 - items/ms: 1363
0215 00:23:55.289229  INFO [polling till empty] num_during_iter: 499851 - removed: cycle/60002 total/4560151 - elapsed_ms: 44 - items/ms: 1363
0215 00:23:58.289512  INFO [polling till empty] num_during_iter: 439849 - removed: cycle/60002 total/4620153 - elapsed_ms: 45 - items/ms: 1333
0215 00:24:00.308987  INFO [polling till empty] num_during_iter: 379847 - removed: cycle/60002 total/4680155 - elapsed_ms: 64 - items/ms: 937
0215 00:24:03.289557  INFO [polling till empty] num_during_iter: 319845 - removed: cycle/60002 total/4740157 - elapsed_ms: 44 - items/ms: 1363
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 12ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 12ms
inner loop longer now 12ms
other work in expiring entries took 525
0215 00:24:07.776642  INFO [polling till empty] num_during_iter: 259843 - removed: cycle/60002 total/4800159 - elapsed_ms: 532 - items/ms: 112
inner loop longer now 13ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 12ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
inner loop longer now 11ms
other work in expiring entries took 433
0215 00:24:08.683650  INFO [polling till empty] num_during_iter: 199841 - removed: cycle/60002 total/4860161 - elapsed_ms: 439 - items/ms: 136
0215 00:24:11.370386  INFO [polling till empty] num_during_iter: 139839 - removed: cycle/60002 total/4920163 - elapsed_ms: 125 - items/ms: 480
0215 00:24:13.372136  INFO [polling till empty] num_during_iter: 79837 - removed: cycle/60002 total/4980165 - elapsed_ms: 127 - items/ms: 472
0215 00:24:16.286089  INFO [polling till empty] num_during_iter: 19835 - removed: cycle/19835 total/5000000 - elapsed_ms: 41 - items/ms: 483
0215 00:24:17.245283  INFO total time syncing cache: 10957ms
0215 00:24:17.245334  INFO longest sync time seen: 3654ms

Results before changing it showed this:

0215 00:28:26.697036  INFO [serial] inserting 5000000 items
0215 00:28:35.977126  INFO done after 9280ms - size: 4999936
0215 00:28:35.977219  INFO [before sync] size: 5000000
0215 00:28:43.015708  INFO [polling till empty] num_during_iter: 5000000 - removed: cycle/60001 total/60001 - elapsed_ms: 36 - items/ms: 1666
0215 00:28:47.014463  INFO [polling till empty] num_during_iter: 4939999 - removed: cycle/60002 total/120003 - elapsed_ms: 35 - items/ms: 1714
0215 00:28:48.013772  INFO [polling till empty] num_during_iter: 4879997 - removed: cycle/60002 total/180005 - elapsed_ms: 35 - items/ms: 1714
0215 00:28:51.020654  INFO [polling till empty] num_during_iter: 4819995 - removed: cycle/60002 total/240007 - elapsed_ms: 42 - items/ms: 1428
0215 00:28:52.983376  INFO [polling till empty] num_during_iter: 4759993 - removed: cycle/3224 total/243231 - elapsed_ms: 4 - items/ms: 806
0215 00:28:54.016071  INFO [polling till empty] num_during_iter: 4756769 - removed: cycle/56778 total/300009 - elapsed_ms: 37 - items/ms: 1534
0215 00:28:56.019840  INFO [polling till empty] num_during_iter: 4699991 - removed: cycle/60002 total/360011 - elapsed_ms: 41 - items/ms: 1463
0215 00:28:59.022875  INFO [polling till empty] num_during_iter: 4639989 - removed: cycle/60002 total/420013 - elapsed_ms: 44 - items/ms: 1363
0215 00:29:01.020195  INFO [polling till empty] num_during_iter: 4579987 - removed: cycle/60002 total/480015 - elapsed_ms: 41 - items/ms: 1463
0215 00:29:04.019431  INFO [polling till empty] num_during_iter: 4519985 - removed: cycle/60002 total/540017 - elapsed_ms: 40 - items/ms: 1500
0215 00:29:07.020925  INFO [polling till empty] num_during_iter: 4459983 - removed: cycle/60002 total/600019 - elapsed_ms: 42 - items/ms: 1428
0215 00:29:09.021071  INFO [polling till empty] num_during_iter: 4399981 - removed: cycle/60002 total/660021 - elapsed_ms: 42 - items/ms: 1428
0215 00:29:12.021859  INFO [polling till empty] num_during_iter: 4339979 - removed: cycle/60002 total/720023 - elapsed_ms: 43 - items/ms: 1395
0215 00:29:13.992883  INFO [polling till empty] num_during_iter: 4279977 - removed: cycle/15786 total/735809 - elapsed_ms: 14 - items/ms: 1127
0215 00:29:16.010206  INFO [polling till empty] num_during_iter: 4264191 - removed: cycle/44216 total/780025 - elapsed_ms: 31 - items/ms: 1426
inner loop longer now 51ms
inner loop longer now 48ms
inner loop longer now 47ms
inner loop longer now 49ms
inner loop longer now 47ms
inner loop longer now 45ms
inner loop longer now 46ms
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 44ms
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 46ms
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 46ms
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 49ms
inner loop longer now 46ms
inner loop longer now 48ms
inner loop longer now 47ms
inner loop longer now 45ms
inner loop longer now 49ms
inner loop longer now 47ms
inner loop longer now 46ms
inner loop longer now 47ms
inner loop longer now 47ms
inner loop longer now 46ms
inner loop longer now 46ms
inner loop longer now 46ms
inner loop longer now 47ms
inner loop longer now 48ms
inner loop longer now 48ms
inner loop longer now 46ms
inner loop longer now 46ms
other work in expiring entries took 1808
0215 00:29:18.792774  INFO [polling till empty] num_during_iter: 4219975 - removed: cycle/60002 total/840027 - elapsed_ms: 1814 - items/ms: 33
inner loop longer now 56ms
inner loop longer now 49ms
inner loop longer now 48ms
inner loop longer now 48ms
inner loop longer now 46ms
inner loop longer now 51ms
inner loop longer now 50ms
inner loop longer now 47ms
inner loop longer now 49ms
inner loop longer now 47ms
inner loop longer now 47ms
inner loop longer now 49ms
inner loop longer now 48ms
inner loop longer now 49ms
inner loop longer now 49ms
inner loop longer now 49ms
inner loop longer now 49ms
inner loop longer now 49ms
inner loop longer now 49ms
inner loop longer now 50ms
inner loop longer now 52ms
inner loop longer now 48ms
inner loop longer now 47ms
inner loop longer now 50ms
inner loop longer now 54ms
inner loop longer now 57ms
inner loop longer now 56ms
other work in expiring entries took 1512
0215 00:29:21.497398  INFO [polling till empty] num_during_iter: 4159973 - removed: cycle/60002 total/900029 - elapsed_ms: 1518 - items/ms: 39
0215 00:29:23.139800  INFO [polling till empty] num_during_iter: 4099971 - removed: cycle/60002 total/960031 - elapsed_ms: 161 - items/ms: 372
0215 00:29:25.135986  INFO [polling till empty] num_during_iter: 4039969 - removed: cycle/60002 total/1020033 - elapsed_ms: 157 - items/ms: 382
0215 00:29:26.994142  INFO [polling till empty] num_during_iter: 3979967 - removed: cycle/4632 total/1024665 - elapsed_ms: 15 - items/ms: 308
0215 00:29:28.057601  INFO [polling till empty] num_during_iter: 3975335 - removed: cycle/55370 total/1080035 - elapsed_ms: 79 - items/ms: 700
0215 00:29:31.026661  INFO [polling till empty] num_during_iter: 3919965 - removed: cycle/60002 total/1140037 - elapsed_ms: 47 - items/ms: 1276
0215 00:29:33.017612  INFO [polling till empty] num_during_iter: 3859963 - removed: cycle/60002 total/1200039 - elapsed_ms: 39 - items/ms: 1538
0215 00:29:35.018555  INFO [polling till empty] num_during_iter: 3799961 - removed: cycle/60002 total/1260041 - elapsed_ms: 39 - items/ms: 1538
0215 00:29:38.020598  INFO [polling till empty] num_during_iter: 3739959 - removed: cycle/60002 total/1320043 - elapsed_ms: 42 - items/ms: 1428
0215 00:29:40.014173  INFO [polling till empty] num_during_iter: 3679957 - removed: cycle/52531 total/1372574 - elapsed_ms: 35 - items/ms: 1500
0215 00:29:40.982811  INFO [polling till empty] num_during_iter: 3627426 - removed: cycle/7471 total/1380045 - elapsed_ms: 4 - items/ms: 1867
0215 00:29:43.017916  INFO [polling till empty] num_during_iter: 3619955 - removed: cycle/60002 total/1440047 - elapsed_ms: 39 - items/ms: 1538
0215 00:29:46.019039  INFO [polling till empty] num_during_iter: 3559953 - removed: cycle/60002 total/1500049 - elapsed_ms: 40 - items/ms: 1500
0215 00:29:49.020344  INFO [polling till empty] num_during_iter: 3499951 - removed: cycle/60002 total/1560051 - elapsed_ms: 41 - items/ms: 1463
0215 00:29:51.019268  INFO [polling till empty] num_during_iter: 3439949 - removed: cycle/60002 total/1620053 - elapsed_ms: 40 - items/ms: 1500
inner loop longer now 45ms
inner loop longer now 45ms
inner loop longer now 40ms
inner loop longer now 41ms
inner loop longer now 39ms
inner loop longer now 37ms
inner loop longer now 41ms
inner loop longer now 38ms
inner loop longer now 44ms
inner loop longer now 41ms
inner loop longer now 40ms
inner loop longer now 37ms
inner loop longer now 40ms
inner loop longer now 37ms
inner loop longer now 36ms
inner loop longer now 38ms
inner loop longer now 37ms
inner loop longer now 38ms
inner loop longer now 39ms
inner loop longer now 38ms
inner loop longer now 37ms
inner loop longer now 37ms
inner loop longer now 40ms
inner loop longer now 37ms
inner loop longer now 40ms
inner loop longer now 37ms
inner loop longer now 39ms
inner loop longer now 39ms
inner loop longer now 38ms
inner loop longer now 38ms
inner loop longer now 38ms
inner loop longer now 39ms
inner loop longer now 38ms
inner loop longer now 40ms
inner loop longer now 37ms
inner loop longer now 38ms
inner loop longer now 38ms
inner loop longer now 38ms
inner loop longer now 37ms
inner loop longer now 37ms
inner loop longer now 39ms
other work in expiring entries took 1695
0215 00:29:55.679426  INFO [polling till empty] num_during_iter: 3379947 - removed: cycle/60002 total/1680055 - elapsed_ms: 1700 - items/ms: 35
inner loop longer now 44ms
inner loop longer now 41ms
inner loop longer now 43ms
inner loop longer now 42ms
inner loop longer now 42ms
inner loop longer now 45ms
inner loop longer now 44ms
inner loop longer now 38ms
inner loop longer now 40ms
inner loop longer now 40ms
inner loop longer now 38ms
inner loop longer now 38ms
inner loop longer now 40ms
inner loop longer now 41ms
inner loop longer now 40ms
inner loop longer now 39ms
inner loop longer now 39ms
inner loop longer now 40ms
inner loop longer now 38ms
inner loop longer now 39ms
inner loop longer now 38ms
inner loop longer now 37ms
inner loop longer now 38ms
other work in expiring entries took 987
0215 00:29:56.969572  INFO [polling till empty] num_during_iter: 3319945 - removed: cycle/18277 total/1698332 - elapsed_ms: 991 - items/ms: 18
0215 00:29:57.081888  INFO [polling till empty] num_during_iter: 3301668 - removed: cycle/41725 total/1740057 - elapsed_ms: 103 - items/ms: 405
0215 00:30:00.124419  INFO [polling till empty] num_during_iter: 3259943 - removed: cycle/60002 total/1800059 - elapsed_ms: 145 - items/ms: 413
0215 00:30:02.123934  INFO [polling till empty] num_during_iter: 3199941 - removed: cycle/60002 total/1860061 - elapsed_ms: 145 - items/ms: 413
0215 00:30:04.064641  INFO [polling till empty] num_during_iter: 3139939 - removed: cycle/60002 total/1920063 - elapsed_ms: 85 - items/ms: 705
0215 00:30:07.022588  INFO [polling till empty] num_during_iter: 3079937 - removed: cycle/60002 total/1980065 - elapsed_ms: 44 - items/ms: 1363
...<etc>
0215 00:32:20.978474  INFO total time syncing cache: 20188ms
0215 00:32:20.978507  INFO longest sync time seen: 1814ms

You'll notice the batch size is locked at 60,002, that's cuz I impl'd the Expiry trait to put a max cap on number of items to be evicted on any given run of .run_pending_tasks() when invoked manually cuz I was trying to restrain these spikes in latency that affect my service.

I'm happy to share the code I'm using for running this benchmark.

Would it be possible to make these settings tunable? What do they even mean? Can you think of anything that would solve my problem? I care more about the blocking nature of evictions than I do memory usage (depending on just how much more and the exact trade-off). I am doing I think ~6k inserts per second on an async Moka cache that can hold however many elements cuz I am bounding it by size in bytes of up to 8GB.

Thank you for any help

@tatsuya6502 tatsuya6502 mentioned this pull request Feb 15, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees

@tatsuya6502 tatsuya6502

Labels
enhancement New feature or request
Projects
None yet
Milestone
v0.7.2
Development

Successfully merging this pull request may close these issues.
2 participants
@tatsuya6502 @texascloud