Nothing urgent, but something I wanted to document somewhere.
I've noticed that jgit gc running inside of gerrit takes a long time to garbage collect the scoring/ores/editquality repo. I wrote a script to parse the gc logs to verify my assumptions:
#!/usr/bin/env python import datetime import re import time with open('/var/log/gerrit/gc_log') as f: gc_log = f.readlines() BEFORE = 'before' AFTER = 'after' def format_time(timestamp): time_obj = time.strptime(timestamp, r'%Y-%m-%d %H:%M:%S,%f') return time.mktime(time_obj) logs = {} for log in gc_log: log_line = re.match( r'^\[([\d-]{10} [\d:,]{12})\].*?: \[(.*?)\] (before|after):', log ) if not log_line: continue timestamp = format_time(log_line.group(1)) repo = log_line.group(2) if not logs.get(repo): logs[repo] = {} if log_line.group(3) == BEFORE: logs[repo]['start'] = timestamp if log_line.group(3) == AFTER: logs[repo]['end'] = timestamp total_seconds = 0 for log in logs: elapsed = logs[log]['end'] - logs[log]['start'] total_seconds += elapsed print('{}\t{}'.format(datetime.timedelta(seconds=elapsed), log)) print('{}\tTOTAL'.format(datetime.timedelta(seconds=total_seconds)))
It seems like more than half of the total git gc time is spent on that repo:
thcipriani@gerrit1001:~$ python elapsed_gc_time.py | sort -rn | head 7:01:27 TOTAL 4:49:00 scoring/ores/editquality 0:30:36 mediawiki/services/ores/editquality 0:07:19 All-Users 0:03:06 operations/debs/pkg-php/php 0:02:51 mediawiki/vagrant 0:02:48 mediawiki/core 0:02:23 analytics/superset/deploy 0:02:16 research/ores/wheels 0:02:16 apps/android/wikipedia
Some discussion on that topic happened during the October 2022 Gerrit community meeting. Some links:
- https://github.blog/2021-08-16-highlights-from-git-2-33/#geometric-repacking (cGit NOT jgit)
- https://gerrit.googlesource.com/gerrit/+/refs/heads/master/contrib/git-exproll.sh
gc log for scoring/ores/editquality:
[2022-10-01 04:12:20,719] INFO : [scoring/ores/editquality] gc config: gc.aggressive=true; [2022-10-01 04:12:20,719] INFO : [scoring/ores/editquality] pack config: maxDeltaDepth=50, deltaSearchWindowSize=10, deltaSearchMemoryLimit=0, deltaCacheSize=52428800, deltaCacheLimit=100, compressionLevel=-1, indexVersion=2, bigFileThreshold=52428800, threads=0, reuseDeltas=true, reuseObjects=true, deltaCompress=true, buildBitmaps=true, bitmapContiguousCommitCount=100, bitmapRecentCommitCount=20000, bitmapRecentCommitSpan=100, bitmapDistantCommitSpan=5000, bitmapExcessiveBranchCount=100, bitmapInactiveBranchAge=90, searchForReuseTimeoutPT596523H14M7S, singlePack=false [2022-10-01 04:12:20,719] INFO : [scoring/ores/editquality] before: numberOfPackedRefs=10, numberOfPackFiles=2, sizeOfLooseObjects=0, numberOfLooseObjects=0, numberOfPackedObjects=8580, numberOfLooseRefs=1, sizeOfPackedObjects=2617021456 [2022-10-01 09:08:43,350] INFO : [scoring/ores/editquality] after: numberOfPackedRefs=10, numberOfPackFiles=2, sizeOfLooseObjects=0, numberOfLooseObjects=0, numberOfPackedObjects=8580, numberOfLooseRefs=1, sizeOfPackedObjects=2617021456