irmin-pack: add GC stats for benchmarking

[metanivek]

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?

[Ngoguey42]

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.

[Ngoguey42]

Here is the draft of what I intend to implement https://github.com/mirage/irmin/commit/167cdc0229dee463e306697335d105057c26940f

[metanivek]

What's the idea behind tracking the various offsets? How do you imagine these being used?

[Ngoguey42]

These offsets give information on the scope of a GC. We may want to plot informations using the offsets as x axis

[Ngoguey42]

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

[Ngoguey42]

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
  ]
}

[Ngoguey42]

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]}

[Ngoguey42]

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]}}

[Ngoguey42]

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]}}