Skip to content

Loadtest BadgerGC #763

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
Draft
wants to merge 1 commit into
base: gc-channel
Choose a base branch
from
Draft

Loadtest BadgerGC #763

wants to merge 1 commit into from

Conversation

stealthybox
Copy link
Member

@stealthybox stealthybox commented May 23, 2025 •
edited
Loading

related #757
issue #748

GH Action failing with SIGBUS
Try running this yourself:

go test -run '^TestBadgerGCLoad$' github.com/fluxcd/image-reflector-controller/internal/database -v -count 1

This test modifies badger to run with less memory and frequent flushes to record-limited vlog files.
The loop starts with around 480,000 image repos and each subsequent loop changes a smaller number of those repos, thus triggering compaction -> discard stats -> GC.

This test on my 14 core apple silicon device causes the GC to also hit its edge-case of 1000 max vlog discards.
If you reduce the GC stop deadline, you can also trigger the error case where Badger rejects the GC request and stops the GC run early.

Example log:

=== RUN   TestBadgerGCLoad
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:03.661593" "level"=0 "msg"="INFO: All 0 tables opened in 0s\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:03.670145" "level"=0 "msg"="INFO: Discard stats nextEmptySlot: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:03.670244" "level"=0 "msg"="INFO: Set nextTxnTs to 0"
    badger_gc.go:61: loaded-badger-gc: "ts"="2025-05-23 17:41:03.670414" "level"=0 "msg"="Starting Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:05.409496" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7329837 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:05.442940" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 106307 keys. Skipped 0 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:05.455821" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: alpine 5: 120000 repos
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:41:23.671816" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:23.671855" "level"=0 "msg"="DEBUG: No file with discard stats"
    badger_gc.go:85: loaded-badger-gc: "ts"="2025-05-23 17:41:23.671864" "level"=1 "msg"="Ran Badger GC" "discarded_vlogs"=0
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:29.328635" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7209369 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:29.362708" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 113680 keys. Skipped 0 keys. Iteration took: 13ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:29.373951" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 99789 keys. Skipped 0 keys. Iteration took: 11ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:29.385336" "level"=0 "msg"="DEBUG: [Compactor: 0] Compaction for level: 0 DONE"
    badger_gc_test.go:92: node 5: 120000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:39.098729" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7248920 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:39.144216" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110713 keys. Skipped 0 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:39.155614" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 92562 keys. Skipped 0 keys. Iteration took: 10ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:39.171966" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: postgres 5: 120000 repos
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:41:43.672032" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:43.672072" "level"=0 "msg"="DEBUG: No file with discard stats"
    badger_gc.go:85: loaded-badger-gc: "ts"="2025-05-23 17:41:43.672083" "level"=1 "msg"="Ran Badger GC" "discarded_vlogs"=0
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:47.110393" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7251023 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:47.143782" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111230 keys. Skipped 0 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:47.156281" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111101 keys. Skipped 0 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:47.165834" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 84615 keys. Skipped 0 keys. Iteration took: 10ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:47.180054" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: debian 5: 120000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:53.386373" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7237583 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:53.448068" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 113460 keys. Skipped 44718 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:53.460660" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111425 keys. Skipped 651 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:53.467091" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 59403 keys. Skipped 0 keys. Iteration took: 6ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:41:53.482403" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: alpine 4: 105000 repos
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:42:03.672703" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:03.786398" "level"=0 "msg"="DEBUG: Discard: 560520 less than threshold: 1212225 for file: 000046.vlog"
    badger_gc.go:85: loaded-badger-gc: "ts"="2025-05-23 17:42:03.786427" "level"=1 "msg"="Ran Badger GC" "discarded_vlogs"=45
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:06.998557" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7222238 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.046858" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111023 keys. Skipped 22180 keys. Iteration took: 15ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.047006" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 79 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.047869" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 113428 keys. Skipped 53714 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.063319" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111305 keys. Skipped 5918 keys. Iteration took: 15ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.071802" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 59554 keys. Skipped 24284 keys. Iteration took: 8ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:07.085121" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: node 4: 105000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:22.416508" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7230268 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:22.457330" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 84616 keys. Skipped 31309 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:22.461079" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 110910 keys. Skipped 36611 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:22.469977" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 59745 keys. Skipped 37310 keys. Iteration took: 9ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:22.487733" "level"=0 "msg"="DEBUG: [Compactor: 1] Compaction for level: 0 DONE"
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:42:23.786599" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:92: postgres 4: 105000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.420656" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7250269 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.458799" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 84617 keys. Skipped 53307 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.463168" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 111425 keys. Skipped 43656 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.475000" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 110954 keys. Skipped 1513 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.483112" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 59580 keys. Skipped 5001 keys. Iteration took: 8ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:29.498463" "level"=0 "msg"="DEBUG: [Compactor: 1] Compaction for level: 0 DONE"
    badger_gc_test.go:92: debian 4: 105000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.737885" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7235444 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.797958" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 113220 keys. Skipped 44425 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.816199" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111491 keys. Skipped 46745 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.828802" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110967 keys. Skipped 13764 keys. Iteration took: 13ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.828859" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 129 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:35.844804" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: alpine 3: 90000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.780580" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7174259 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.811542" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 59710 keys. Skipped 2430 keys. Iteration took: 11ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.822223" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 113220 keys. Skipped 44899 keys. Iteration took: 20ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.827226" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.833354" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.834223" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 111512 keys. Skipped 0 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.839047" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.841356" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.843621" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.845974" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.847966" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.852141" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 110945 keys. Skipped 58555 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.853025" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.869167" "level"=0 "msg"="DEBUG: [Compactor: 0] Compaction for level: 0 DONE"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.875926" "level"=0 "msg"="DEBUG: 5 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.875946" "level"=0 "msg"="INFO: Processed 5 entries in 1 loops"
    badger_gc_test.go:131: "ts"="2025-05-23 17:42:52.875966" "level"=0 "msg"="INFO: Total entries: 133. Moved: 77"
    badger_gc.go:93: loaded-badger-gc: "ts"="2025-05-23 17:42:55.645123" "msg"="Warning: Badger GC ran for maximum discards" "error"=null "discarded_vlogs"=1000
    badger_gc_test.go:92: node 3: 90000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:02.890757" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7160597 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:02.946451" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111194 keys. Skipped 17344 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:02.964938" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111905 keys. Skipped 79576 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:02.968705" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 32173 keys. Skipped 5717 keys. Iteration took: 4ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:02.984902" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: postgres 3: 90000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.777087" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7147849 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.804854" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 32174 keys. Skipped 16457 keys. Iteration took: 5ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.818262" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 110918 keys. Skipped 84136 keys. Iteration took: 19ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.831677" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 111183 keys. Skipped 2701 keys. Iteration took: 13ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.844715" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 111826 keys. Skipped 0 keys. Iteration took: 13ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.844837" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 683 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:11.863020" "level"=0 "msg"="DEBUG: [Compactor: 1] Compaction for level: 0 DONE"
    badger_gc_test.go:92: debian 3: 90000 repos
    badger_gc_test.go:92: alpine 2: 75000 repos
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:43:15.646269" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.075636" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7134433 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.110313" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 111827 keys. Skipped 2467 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.116351" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 113447 keys. Skipped 74347 keys. Iteration took: 21ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.129167" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 110890 keys. Skipped 654 keys. Iteration took: 13ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.144216" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 110593 keys. Skipped 26982 keys. Iteration took: 15ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.144316" "level"=0 "msg"="DEBUG: [1] LOG Compact. Added 390 keys. Skipped 38 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.144691" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.147047" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.154028" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.160572" "level"=0 "msg"="DEBUG: [Compactor: 1] Compaction for level: 0 DONE"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.184115" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.184127" "level"=0 "msg"="INFO: Processed 9 entries in 1 loops"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:22.184155" "level"=0 "msg"="INFO: Total entries: 133. Moved: 36"
    badger_gc_test.go:92: node 2: 75000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.863388" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7147162 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.887587" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 32858 keys. Skipped 3283 keys. Iteration took: 5ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.898690" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110939 keys. Skipped 48678 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.916758" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111855 keys. Skipped 51603 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.916813" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 15 keys. Skipped 1 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.935689" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.964173" "level"=0 "msg"="INFO: Processed 2 entries in 1 loops"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:35.964206" "level"=0 "msg"="INFO: Total entries: 139. Moved: 2"
    badger_gc_test.go:92: postgres 2: 75000 repos
    badger_gc_test.go:92: debian 2: 75000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.336826" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7149112 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.397212" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111856 keys. Skipped 15560 keys. Iteration took: 15ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.398144" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 113206 keys. Skipped 8098 keys. Iteration took: 15ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.402420" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 32873 keys. Skipped 4590 keys. Iteration took: 5ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.418139" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111117 keys. Skipped 73501 keys. Iteration took: 19ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.429952" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110928 keys. Skipped 1569 keys. Iteration took: 12ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.429993" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 24 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:44.450405" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: alpine 1: 60000 repos
    badger_gc.go:93: loaded-badger-gc: "ts"="2025-05-23 17:43:47.917918" "msg"="Warning: Badger GC ran for maximum discards" "error"=null "discarded_vlogs"=1000
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.484345" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7125967 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.515258" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 111840 keys. Skipped 2473 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.515337" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 41 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.518697" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 113206 keys. Skipped 51225 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.532318" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 111107 keys. Skipped 611 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.549322" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 110593 keys. Skipped 50694 keys. Iteration took: 17ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.549405" "level"=0 "msg"="DEBUG: [0] LOG Compact. Added 344 keys. Skipped 34 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:43:59.567957" "level"=0 "msg"="DEBUG: [Compactor: 0] Compaction for level: 0 DONE"
    badger_gc_test.go:92: node 1: 60000 repos
    badger_gc_test.go:92: postgres 1: 60000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.905678" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7156533 size of flushChan: 0\n"
    badger_gc.go:80: loaded-badger-gc: "ts"="2025-05-23 17:44:07.918111" "level"=1 "msg"="Running Badger GC"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.949776" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111182 keys. Skipped 34163 keys. Iteration took: 17ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.950684" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111769 keys. Skipped 56705 keys. Iteration took: 18ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.955872" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 32986 keys. Skipped 3296 keys. Iteration took: 5ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.964218" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110607 keys. Skipped 8360 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.964295" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 254 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:07.978682" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:92: debian 1: 60000 repos
    badger_gc_test.go:92: alpine 0: 45000 repos
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.006127" "level"=0 "msg"="DEBUG: Flushing memtable, mt.size=7134154 size of flushChan: 0\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.046425" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111780 keys. Skipped 2499 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.046523" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 244 keys. Skipped 0 keys. Iteration took: 0s"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.049926" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 113338 keys. Skipped 44338 keys. Iteration took: 17ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.065483" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 111177 keys. Skipped 24941 keys. Iteration took: 16ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.072033" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.074091" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.076695" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.078682" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.079715" "level"=0 "msg"="DEBUG: [2] LOG Compact. Added 110479 keys. Skipped 32935 keys. Iteration took: 14ms"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.085144" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.093865" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.097722" "level"=0 "msg"="DEBUG: 9 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.100700" "level"=0 "msg"="DEBUG: [Compactor: 2] Compaction for level: 0 DONE"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.117832" "level"=0 "msg"="DEBUG: 1 entries written"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.117853" "level"=0 "msg"="INFO: Processed 1 entries in 1 loops"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:22.117865" "level"=0 "msg"="INFO: Total entries: 133. Moved: 64"
    badger_gc_test.go:92: node 0: 45000 repos
    badger_gc_test.go:92: postgres 0: 45000 repos
    badger_gc_test.go:92: debian 0: 45000 repos
    badger_gc_test.go:98: waiting for GC stop
    badger_gc.go:93: loaded-badger-gc: "ts"="2025-05-23 17:44:37.234419" "msg"="Warning: Badger GC ran for maximum discards" "error"=null "discarded_vlogs"=1000
    badger_gc.go:70: loaded-badger-gc: "ts"="2025-05-23 17:44:37.234450" "level"=0 "msg"="Stopped Badger GC"
    badger_gc_test.go:103: GC Stopped
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.234853" "level"=0 "msg"="DEBUG: Closing database"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.235042" "level"=0 "msg"="INFO: Lifetime L0 stalled for: 0s\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.235060" "level"=0 "msg"="DEBUG: Flushing memtable"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.235071" "level"=0 "msg"="DEBUG: pushed to flush chan\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.248600" "level"=0 "msg"="DEBUG: Stopping garbage collection of values."
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.425674" "level"=0 "msg"="INFO: \nLevel 0 [ ]: NumTables: 01. Size: 1.8 MiB of 0 B. Score: 1.00->1.18 StaleData: 0 B Target FileSize: 8.0 MiB\nLevel 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel 5 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel 6 [B]: NumTables: 06. Size: 8.5 MiB of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB\nLevel Done\n"
    badger_gc_test.go:131: "ts"="2025-05-23 17:44:37.425917" "level"=0 "msg"="DEBUG: Waiting for closer"
--- PASS: TestBadgerGCLoad (214.86s)
PASS
ok  	github.com/fluxcd/image-reflector-controller/internal/database	215.172s

@stealthybox stealthybox added the area/testing Testing related issues and pull requests label May 23, 2025
@stealthybox stealthybox changed the base branch from main to gc-channel May 23, 2025 07:36
@stealthybox stealthybox force-pushed the gc-loadtest branch 3 times, most recently from fb93d17 to 3ab825a Compare May 23, 2025 08:16
@stealthybox stealthybox mentioned this pull request May 23, 2025
Merged
@stealthybox
Load Test BadgerGC
0b522a0 
Signed-off-by: leigh capili <[email protected]>
@stealthybox stealthybox mentioned this pull request May 23, 2025
Open
@stealthybox
Copy link
Member Author

A release candidate for this garbage-collection logic is cut:

  • ghcr.io/fluxcd/image-reflector-controller:rc-c4913021
  • docker.io/fluxcd/image-reflector-controller:rc-c4913021

Updated CRD's:
kustomize build https://github.com/fluxcd/image-reflector-controller//config/crd/

@stealthybox stealthybox mentioned this pull request May 24, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
area/testing Testing related issues and pull requests
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
1 participant
@stealthybox