irmin
irmin copied to clipboard
mirage
irmin-pack: add GC stats for benchmarking
Things to add to our stats summary
- Current gc stats type for each gc run https://github.com/mirage/irmin/blob/953431ee9ef6f94dc35950b1edc78c34b881b5b9/src/irmin-pack/unix/ext.ml#L147-L154
- Memory usage of child process
- What else?
Additionally:
- The various offsets when the gc starts: suffix_start_offset, commit_offset, suffix_end_offset
- The suffix_end_offset when the gc finalises.
- New counters from file_manager and IO
- In the stats trace, we need to be able to tell if a GC was ongoing for each block
Additionally, from the GC worker:
- the runtime of various portions of the code
- number of objects traversed
- number of objects copied
- size of temporary files
- rusage stats at the end of run
- disk reads/writes (even if we can't count the ones from mmap)
- pack stats
- gc stats
- %cpu time
Injecting these stats in the stats_trace may be challenging. The stats_trace pushes one entry per event on the lib_context-API. The GC finalisation is not a lib_context-API event.
Here is the draft of what I intend to implement https://github.com/mirage/irmin/commit/167cdc0229dee463e306697335d105057c26940f
What's the idea behind tracking the various offsets? How do you imagine these being used?
These offsets give information on the scope of a GC. We may want to plot informations using the offsets as x axis
New version of the draft. The content of the stats did not change much. I have implemented the collection for the worker stats https://github.com/mirage/irmin/commit/8d337a62469ece8920a36a195becd7d7725f1604
The worker stats on 10k commits (using tree.exe).
{
"rusage": {
"maxrss_before": 843,
"maxrss_after": 725430,
"minflt": 284420,
"majflt": 981,
"inblock": 0,
"oublock": 0,
"nvcsw": 64,
"nivcsw": 695
},
"ocaml_gc": {
"minor_words": 109509416,
"promoted_words": 6441484,
"major_words": 34254979,
"minor_collections": 512,
"major_collections": 3,
"heap_words_before": 65688064,
"heap_words_after": 99904512,
"compactions": 0,
"top_heap_words_before": 71514112,
"top_heap_words_after": 99904512,
"stack_size_before": 248,
"stack_size_after": 260
},
"index": {
"bytes_read": 0,
"nb_reads": 0,
"bytes_written": 0,
"nb_writes": 0,
"nb_merge": 0,
"nb_replace": 0,
"nb_sync": 0,
"time_sync": 0,
"lru_hits": 0,
"lru_misses": 0
},
"pack_store": {
"appended_hashes": 0,
"appended_offsets": 0,
"total": 188595,
"from_staging": 0,
"from_lru": 0,
"from_pack_direct": 188595,
"from_pack_indexed": 0
},
"inode": {
"inode_add": 816822,
"inode_remove": 9678,
"inode_of_seq": 261000,
"inode_of_raw": 2574260,
"inode_rec_add": 970557,
"inode_rec_remove": 12063,
"inode_to_binv": 1094135,
"inode_decode_bin": 381639,
"inode_encode_bin": 997996
},
"wall_durations": [
[
"open files",
0.2054217549739406
],
[
"load commit",
6.51930458843708e-05
],
[
"mapping: start",
0.0001667760079726577
],
[
"mapping: commits to sorted",
5.7829893194139e-06
],
[
"mapping: objects to sorted",
0.8073132769786753
],
[
"mapping: of sorted",
0.7211549649946392
],
[
"prefix: start",
7.134000770747662e-05
],
[
"prefix: transfer",
0.03764474397758022
],
[
"prefix: rewrite commit parents",
0.001322036026977003
],
[
"suffix: start",
0.0001387150259688497
],
[
"suffix: transfer",
0.4972987559740432
]
],
"sys_durations": [
[
"open files",
0.08071099999999999
],
[
"load commit",
2.900000000000125e-05
],
[
"mapping: start",
0.0001430000000000042
],
[
"mapping: commits to sorted",
2.000000000002e-06
],
[
"mapping: objects to sorted",
0.28335
],
[
"mapping: of sorted",
0.193393
],
[
"prefix: start",
6.500000000009276e-05
],
[
"prefix: transfer",
0.012293
],
[
"prefix: rewrite commit parents",
0.0001149999999999762
],
[
"suffix: start",
0.000124000000000013
],
[
"suffix: transfer",
0.107379
]
],
"user_durations": [
[
"open files",
0.119988
],
[
"load commit",
3.499999999999337e-05
],
[
"mapping: start",
2.400000000001012e-05
],
[
"mapping: commits to sorted",
2.999999999989122e-06
],
[
"mapping: objects to sorted",
0.518904
],
[
"mapping: of sorted",
0.525864
],
[
"prefix: start",
5.999999999950489e-06
],
[
"prefix: transfer",
0.02292800000000006
],
[
"prefix: rewrite commit parents",
2.699999999999925e-05
],
[
"suffix: start",
1.300000000004076e-05
],
[
"suffix: transfer",
0.355232
]
],
"objects_traversed": 251296,
"suffix_transfers": [
87852012,
1031295,
0
]
}
Same setup, better stats
{'files': [['prefix', 12801778], ['mapping', 48], ['sorted', 4020736], ['reachable', 4020736]],
'index': {'bytes_read': 123127436,
'bytes_written': 104720533,
'lru_hits': 0,
'lru_misses': 0,
'nb_merge': 0,
'nb_reads': 455572,
'nb_replace': 0,
'nb_sync': 3,
'nb_writes': 108,
'time_sync': 45.456},
'inode': {'inode_add': 816822,
'inode_decode_bin': 381639,
'inode_encode_bin': 997996,
'inode_of_raw': 2574260,
'inode_of_seq': 261000,
'inode_rec_add': 970557,
'inode_rec_remove': 12063,
'inode_remove': 9678,
'inode_to_binv': 1094135},
'objects_traversed': 251296,
'ocaml_gc': {'compactions': 0,
'heap_words_after': 86873088,
'heap_words_before': 57119744,
'major_collections': 2,
'major_words': 33625577,
'minor_collections': 505,
'minor_words': 108496228,
'promoted_words': 6059226,
'stack_size_after': 258,
'stack_size_before': 248,
'top_heap_words_after': 86873088,
'top_heap_words_before': 71514112},
'pack_store': {'appended_hashes': 0,
'appended_offsets': 0,
'from_lru': 0,
'from_pack_direct': 188595,
'from_pack_indexed': 0,
'from_staging': 0,
'total': 188595},
'rusage': {'inblock': 0,
'majflt': 981,
'maxrss_after': 556158,
'maxrss_before': 888,
'minflt': 225571,
'nivcsw': 3271,
'nvcsw': 1156,
'oublock': 0},
'steps': [['open files', {'sys': 0.231429, 'user': 0.259585, 'wall': 0.4981800820096396}],
['load commit', {'sys': 0.0003910000000000025, 'user': 5.600000000000049e-05, 'wall': 0.001599935989361256}],
['mapping: start', {'sys': 0.0001470000000000082, 'user': 2.399999999996849e-05, 'wall': 0.0001713389647193253}],
['mapping: commits to sorted', {'sys': 3.999999999976245e-06, 'user': 6.000000000006001e-06, 'wall': 9.643030352890491e-06}],
['mapping: objects to sorted', {'sys': 0.31494, 'user': 0.610779, 'wall': 1.163674118986819}],
['mapping: of sorted', {'sys': 0.03394200000000003, 'user': 0.09932299999999994, 'wall': 0.1396132860099897}],
['prefix: start', {'sys': 0.0001939999999999165, 'user': 0.0001330000000000497, 'wall': 0.0003048679791390896}],
['prefix: transfer', {'sys': 0.03862600000000005, 'user': 0.0808580000000001, 'wall': 0.1332227060338482}],
['prefix: rewrite commit parents', {'sys': 0.000124000000000013, 'user': 5.599999999983396e-05, 'wall': 0.001542577985674143}],
['suffix: start', {'sys': 0.0001590000000000202, 'user': 2.199999999996649e-05, 'wall': 0.0001831519766710699}],
['suffix: transfer', {'sys': 0.134019, 'user': 0.4597760000000002, 'wall': 0.7144023950095288}]],
'suffix_transfers': [86632740, 1265165, 0]}
Same setup, but all the stats (not just from worker). PR will follow soon
{'after_suffix_end_offset': 101225952,
'after_suffix_start_offset': 12801997,
'before_suffix_end_offset': 97315611,
'before_suffix_start_offset': 0,
'commit_offset': 12801997,
'steps': [['worker startup', {'sys': 6.700000000003925e-05, 'user': 0.00182599999999411, 'wall': 0.001892900094389915}],
['before finalise', {'sys': 0.1598659999999998, 'user': 1.470254000000004, 'wall': 1.713056299835443}],
['worker wait', {'sys': 0, 'user': 8.000000001118224e-06, 'wall': 8.400063961744308e-06}],
['read output', {'sys': 0, 'user': 0.0004609999999942715, 'wall': 0.0004603001289069653}],
['copy latest newies', {'sys': 0, 'user': 0.0525170000000017, 'wall': 0.05251449998468161}],
['swap and purge', {'sys': 0, 'user': 0.005549000000002025, 'wall': 0.005547999870032072}],
['unlink', {'sys': 0.006770000000000165, 'user': 0, 'wall': 0.006773099768906832}]],
'worker': {'files': [['suffix', 100640256], ['prefix', 12801778], ['mapping', 48], ['sorted', 4020736], ['reachable', 4020736]],
'index': {'bytes_read': 123067185,
'bytes_written': 104660887,
'lru_hits': 0,
'lru_misses': 0,
'nb_merge': 0,
'nb_reads': 455557,
'nb_replace': 0,
'nb_sync': 3,
'nb_writes': 108,
'time_sync': 25.5},
'inode': {'inode_add': 816822,
'inode_decode_bin': 381639,
'inode_encode_bin': 997996,
'inode_of_raw': 2574260,
'inode_of_seq': 261000,
'inode_rec_add': 970557,
'inode_rec_remove': 12063,
'inode_remove': 9678,
'inode_to_binv': 1094135},
'objects_traversed': 251296,
'ocaml_gc': {'compactions': 0,
'heap_words_after': 52683776,
'heap_words_before': 30121472,
'major_collections': 4,
'major_words': 33699583,
'minor_collections': 506,
'minor_words': 108495936,
'promoted_words': 6148389,
'stack_size_after': 254,
'stack_size_before': 248,
'top_heap_words_after': 74928640,
'top_heap_words_before': 74928640},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 188595, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 188595},
'rusage': {'inblock': 0, 'majflt': 1, 'maxrss_after': 432060, 'maxrss_before': 252512, 'minflt': 7282, 'nivcsw': 2, 'nvcsw': 60, 'oublock': 212288},
'steps': [['open files', {'sys': 0, 'user': 0.068424, 'wall': 0.06946479994803667}],
['load commit', {'sys': 0, 'user': 2.499999999999725e-05, 'wall': 2.709962427616119e-05}],
['mapping: start', {'sys': 0, 'user': 7.000000000000062e-05, 'wall': 6.930017843842506e-05}],
['mapping: commits to sorted', {'sys': 0, 'user': 2.000000000002e-06, 'wall': 3.300141543149948e-06}],
['mapping: objects to sorted', {'sys': 0.109534, 'user': 0.448442, 'wall': 0.5579733997583389}],
['mapping: of sorted', {'sys': 0.01845099999999998, 'user': 0.151661, 'wall': 0.175475399941206}],
['prefix: start', {'sys': 3.000000000003e-06, 'user': 1.799999999996249e-05, 'wall': 2.240017056465149e-05}],
['prefix: transfer', {'sys': 0.03057400000000002, 'user': 0.05396400000000001, 'wall': 0.08453390002250671}],
['prefix: rewrite commit parents', {'sys': 0.0003930000000000045, 'user': 0.001792000000000016, 'wall': 0.02977370005100965}],
['suffix: start', {'sys': 6.999999999979245e-06, 'user': 3.300000000006076e-05, 'wall': 4.180008545517921e-05}],
['suffix: transfer', {'sys': 0.040663, 'user': 0.5722999999999999, 'wall': 0.6129699000157416}]],
'suffix_transfers': [86588407, 1238569, 11283]}}
Now more stats worker per step:
{'after_suffix_end_offset': 100341260,
'after_suffix_start_offset': 12801997,
'before_suffix_end_offset': 97315611,
'before_suffix_start_offset': 0,
'commit_offset': 12801997,
'steps': [['worker startup', {'sys': 0.003403999999999741, 'user': 6.600000000389628e-05, 'wall': 0.00346738297957927}],
['before finalise', {'sys': 0.2840850000000001, 'user': 1.469582000000003, 'wall': 2.223257635021582}],
['worker wait', {'sys': 1.000000000006551e-05, 'user': 5.999999999062311e-06, 'wall': 1.632398925721645e-05}],
['read output', {'sys': 8.799999999986596e-05, 'user': 0.002854999999996721, 'wall': 0.002941373968496919}],
['copy latest newies', {'sys': 0.000243999999999911, 'user': 4.700000000212867e-05, 'wall': 0.000293026037979871}],
['swap and purge', {'sys': 0.0005260000000002485, 'user': 0.004672999999996819, 'wall': 0.00519815000006929}],
['unlink', {'sys': 0.004688999999999943, 'user': 3.000000000241698e-05, 'wall': 0.004719047981780022}]],
'suffix_transfer': -84493829,
'worker': {'files': [['suffix', 100321475], ['prefix', 12801778], ['mapping', 48], ['sorted', 4020736], ['reachable', 4020736]],
'initial_heap_words': 26533376,
'initial_maxrss': 823,
'initial_stack_size': 242,
'initial_top_heap_words': 75541504,
'objects_traversed': 251296,
'steps': [['open files',
{'duration': {'sys': 0.035332, 'user': 0.052752, 'wall': 0.09926390298642218},
'index': {'bytes_read': 2097080, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 3095, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 1221141, 'minor_collections': 6, 'minor_words': 1380914, 'promoted_words': 666154, 'stack_size': 258, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 56967, 'minflt': 23539, 'nivcsw': 62, 'nvcsw': 4, 'oublock': 0}}],
['load commit',
{'duration': {'sys': 0.0002030000000000018, 'user': 0.0001749999999999946, 'wall': 0.001050796010531485},
'index': {'bytes_read': 152, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 3, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 24582, 'minor_collections': 0, 'minor_words': 17960, 'promoted_words': 0, 'stack_size': 258, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 1, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 1},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 57266, 'minflt': 80, 'nivcsw': 0, 'nvcsw': 2, 'oublock': 0}}],
['mapping: start',
{'duration': {'sys': 0.0001400000000000012, 'user': 7.500000000000562e-05, 'wall': 0.0002141479635611176},
'index': {'bytes_read': 0, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 0, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 24582, 'minor_collections': 0, 'minor_words': 17816, 'promoted_words': 0, 'stack_size': 276, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 57298, 'minflt': 8, 'nivcsw': 0, 'nvcsw': 0, 'oublock': 0}}],
['mapping: commits to sorted',
{'duration': {'sys': 5.999999999999062e-06, 'user': 4.499999999999643e-05, 'wall': 5.215202691033483e-05},
'index': {'bytes_read': 0, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 0, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 24582, 'minor_collections': 0, 'minor_words': 17557, 'promoted_words': 0, 'stack_size': 276, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 57315, 'minflt': 4, 'nivcsw': 0, 'nvcsw': 0, 'oublock': 0}}],
['mapping: objects to sorted',
{'duration': {'sys': 0.354627, 'user': 0.686673, 'wall': 1.202150552999228},
'index': {'bytes_read': 20298419, 'bytes_written': 4000000, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 439888, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 4, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 188594, 'inode_encode_bin': 0, 'inode_of_raw': 188594, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 1, 'major_words': 2327435, 'minor_collections': 330, 'minor_words': 86293681, 'promoted_words': 1019706, 'stack_size': 276, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 188594, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 188594},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 160141, 'minflt': 44426, 'nivcsw': 348, 'nvcsw': 977, 'oublock': 0}}],
['mapping: of sorted',
{'duration': {'sys': 0.014849, 'user': 0.1389360000000001, 'wall': 0.1540616250131279},
'index': {'bytes_read': 0, 'bytes_written': 20784, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 0, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 2, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 4512300, 'minor_collections': 80, 'minor_words': 20954114, 'promoted_words': 4485124, 'stack_size': 258, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 981, 'maxrss': 192122, 'minflt': 8581, 'nivcsw': 9, 'nvcsw': 1, 'oublock': 0}}],
['prefix: start',
{'duration': {'sys': 0.0003979999999999539, 'user': 0.0005689999999999307, 'wall': 0.0009675069595687091},
'index': {'bytes_read': 0, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 0, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 24582, 'minor_collections': 0, 'minor_words': 17658, 'promoted_words': 0, 'stack_size': 268, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 192139, 'minflt': 4, 'nivcsw': 0, 'nvcsw': 0, 'oublock': 0}}],
['prefix: transfer',
{'duration': {'sys': 0.01853500000000002, 'user': 0.138367, 'wall': 0.1579513300093822},
'index': {'bytes_read': 12801778, 'bytes_written': 12801778, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 1564, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 13, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 1, 'major_words': 3489694, 'minor_collections': 11, 'minor_words': 33459, 'promoted_words': 386, 'stack_size': 258, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 219471, 'minflt': 6674, 'nivcsw': 45, 'nvcsw': 2, 'oublock': 0}}],
['prefix: rewrite commit parents',
{'duration': {'sys': 9.700000000001374e-05, 'user': 8.900000000000574e-05, 'wall': 0.00140581902815029},
'index': {'bytes_read': 66, 'bytes_written': 66, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 1, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 1, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 24582, 'minor_collections': 0, 'minor_words': 17901, 'promoted_words': 0, 'stack_size': 258, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 219484, 'minflt': 3, 'nivcsw': 0, 'nvcsw': 1, 'oublock': 0}}],
['suffix: start',
{'duration': {'sys': 0.000105999999999995, 'user': 6.299999999992423e-05, 'wall': 0.0001690349890850484},
'index': {'bytes_read': 0, 'bytes_written': 0, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 0, 'nb_replace': 0, 'nb_sync': 0, 'nb_writes': 0, 'time_sync': 0},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 26533376, 'major_collections': 0, 'major_words': 25608, 'minor_collections': 0, 'minor_words': 17659, 'promoted_words': 0, 'stack_size': 260, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 219500, 'minflt': 4, 'nivcsw': 0, 'nvcsw': 0, 'oublock': 0}}],
['suffix: transfer',
{'duration': {'sys': 0.119127, 'user': 0.384422, 'wall': 0.5845761569798924},
'index': {'bytes_read': 87548401, 'bytes_written': 87519478, 'lru_hits': 0, 'lru_misses': 0, 'nb_merge': 0, 'nb_reads': 10944, 'nb_replace': 0, 'nb_sync': 3, 'nb_writes': 87, 'time_sync': 35.732},
'inode': {'inode_add': 0, 'inode_decode_bin': 0, 'inode_encode_bin': 0, 'inode_of_raw': 0, 'inode_of_seq': 0, 'inode_rec_add': 0, 'inode_rec_remove': 0, 'inode_remove': 0, 'inode_to_binv': 0},
'ocaml_gc': {'compactions': 0, 'heap_words': 35090944, 'major_collections': 2, 'major_words': 22193229, 'minor_collections': 80, 'minor_words': 150500, 'promoted_words': 3947, 'stack_size': 262, 'top_heap_words': 75541504},
'pack_store': {'appended_hashes': 0, 'appended_offsets': 0, 'from_lru': 0, 'from_pack_direct': 0, 'from_pack_indexed': 0, 'from_staging': 0, 'total': 0},
'rusage': {'inblock': 0, 'majflt': 0, 'maxrss': 290279, 'minflt': 20271, 'nivcsw': 595, 'nvcsw': 70, 'oublock': 0}}]],
'suffix_transfers': [86632740, 886738, 0]}}