git@vger.kernel.org list mirror (unofficial, one of many)
 help / color / Atom feed
43adbf00eb9096c09ebb4a2ea16cfb0ff2fe7fbd blob 45210 bytes (raw)

   1
   2
   3
   4
   5
   6
   7
   8
   9
  10
  11
  12
  13
  14
  15
  16
  17
  18
  19
  20
  21
  22
  23
  24
  25
  26
  27
  28
  29
  30
  31
  32
  33
  34
  35
  36
  37
  38
  39
  40
  41
  42
  43
  44
  45
  46
  47
  48
  49
  50
  51
  52
  53
  54
  55
  56
  57
  58
  59
  60
  61
  62
  63
  64
  65
  66
  67
  68
  69
  70
  71
  72
  73
  74
  75
  76
  77
  78
  79
  80
  81
  82
  83
  84
  85
  86
  87
  88
  89
  90
  91
  92
  93
  94
  95
  96
  97
  98
  99
 100
 101
 102
 103
 104
 105
 106
 107
 108
 109
 110
 111
 112
 113
 114
 115
 116
 117
 118
 119
 120
 121
 122
 123
 124
 125
 126
 127
 128
 129
 130
 131
 132
 133
 134
 135
 136
 137
 138
 139
 140
 141
 142
 143
 144
 145
 146
 147
 148
 149
 150
 151
 152
 153
 154
 155
 156
 157
 158
 159
 160
 161
 162
 163
 164
 165
 166
 167
 168
 169
 170
 171
 172
 173
 174
 175
 176
 177
 178
 179
 180
 181
 182
 183
 184
 185
 186
 187
 188
 189
 190
 191
 192
 193
 194
 195
 196
 197
 198
 199
 200
 201
 202
 203
 204
 205
 206
 207
 208
 209
 210
 211
 212
 213
 214
 215
 216
 217
 218
 219
 220
 221
 222
 223
 224
 225
 226
 227
 228
 229
 230
 231
 232
 233
 234
 235
 236
 237
 238
 239
 240
 241
 242
 243
 244
 245
 246
 247
 248
 249
 250
 251
 252
 253
 254
 255
 256
 257
 258
 259
 260
 261
 262
 263
 264
 265
 266
 267
 268
 269
 270
 271
 272
 273
 274
 275
 276
 277
 278
 279
 280
 281
 282
 283
 284
 285
 286
 287
 288
 289
 290
 291
 292
 293
 294
 295
 296
 297
 298
 299
 300
 301
 302
 303
 304
 305
 306
 307
 308
 309
 310
 311
 312
 313
 314
 315
 316
 317
 318
 319
 320
 321
 322
 323
 324
 325
 326
 327
 328
 329
 330
 331
 332
 333
 334
 335
 336
 337
 338
 339
 340
 341
 342
 343
 344
 345
 346
 347
 348
 349
 350
 351
 352
 353
 354
 355
 356
 357
 358
 359
 360
 361
 362
 363
 364
 365
 366
 367
 368
 369
 370
 371
 372
 373
 374
 375
 376
 377
 378
 379
 380
 381
 382
 383
 384
 385
 386
 387
 388
 389
 390
 391
 392
 393
 394
 395
 396
 397
 398
 399
 400
 401
 402
 403
 404
 405
 406
 407
 408
 409
 410
 411
 412
 413
 414
 415
 416
 417
 418
 419
 420
 421
 422
 423
 424
 425
 426
 427
 428
 429
 430
 431
 432
 433
 434
 435
 436
 437
 438
 439
 440
 441
 442
 443
 444
 445
 446
 447
 448
 449
 450
 451
 452
 453
 454
 455
 456
 457
 458
 459
 460
 461
 462
 463
 464
 465
 466
 467
 468
 469
 470
 471
 472
 473
 474
 475
 476
 477
 478
 479
 480
 481
 482
 483
 484
 485
 486
 487
 488
 489
 490
 491
 492
 493
 494
 495
 496
 497
 498
 499
 500
 501
 502
 503
 504
 505
 506
 507
 508
 509
 510
 511
 512
 513
 514
 515
 516
 517
 518
 519
 520
 521
 522
 523
 524
 525
 526
 527
 528
 529
 530
 531
 532
 533
 534
 535
 536
 537
 538
 539
 540
 541
 542
 543
 544
 545
 546
 547
 548
 549
 550
 551
 552
 553
 554
 555
 556
 557
 558
 559
 560
 561
 562
 563
 564
 565
 566
 567
 568
 569
 570
 571
 572
 573
 574
 575
 576
 577
 578
 579
 580
 581
 582
 583
 584
 585
 586
 587
 588
 589
 590
 591
 592
 593
 594
 595
 596
 597
 598
 599
 600
 601
 602
 603
 604
 605
 606
 607
 608
 609
 610
 611
 612
 613
 614
 615
 616
 617
 618
 619
 620
 621
 622
 623
 624
 625
 626
 627
 628
 629
 630
 631
 632
 633
 634
 635
 636
 637
 638
 639
 640
 641
 642
 643
 644
 645
 646
 647
 648
 649
 650
 651
 652
 653
 654
 655
 656
 657
 658
 659
 660
 661
 662
 663
 664
 665
 666
 667
 668
 669
 670
 671
 672
 673
 674
 675
 676
 677
 678
 679
 680
 681
 682
 683
 684
 685
 686
 687
 688
 689
 690
 691
 692
 693
 694
 695
 696
 697
 698
 699
 700
 701
 702
 703
 704
 705
 706
 707
 708
 709
 710
 711
 712
 713
 714
 715
 716
 717
 718
 719
 720
 721
 722
 723
 724
 725
 726
 727
 728
 729
 730
 731
 732
 733
 734
 735
 736
 737
 738
 739
 740
 741
 742
 743
 744
 745
 746
 747
 748
 749
 750
 751
 752
 753
 754
 755
 756
 757
 758
 759
 760
 761
 762
 763
 764
 765
 766
 767
 768
 769
 770
 771
 772
 773
 774
 775
 776
 777
 778
 779
 780
 781
 782
 783
 784
 785
 786
 787
 788
 789
 790
 791
 792
 793
 794
 795
 796
 797
 798
 799
 800
 801
 802
 803
 804
 805
 806
 807
 808
 809
 810
 811
 812
 813
 814
 815
 816
 817
 818
 819
 820
 821
 822
 823
 824
 825
 826
 827
 828
 829
 830
 831
 832
 833
 834
 835
 836
 837
 838
 839
 840
 841
 842
 843
 844
 845
 846
 847
 848
 849
 850
 851
 852
 853
 854
 855
 856
 857
 858
 859
 860
 861
 862
 863
 864
 865
 866
 867
 868
 869
 870
 871
 872
 873
 874
 875
 876
 877
 878
 879
 880
 881
 882
 883
 884
 885
 886
 887
 888
 889
 890
 891
 892
 893
 894
 895
 896
 897
 898
 899
 900
 901
 902
 903
 904
 905
 906
 907
 908
 909
 910
 911
 912
 913
 914
 915
 916
 917
 918
 919
 920
 921
 922
 923
 924
 925
 926
 927
 928
 929
 930
 931
 932
 933
 934
 935
 936
 937
 938
 939
 940
 941
 942
 943
 944
 945
 946
 947
 948
 949
 950
 951
 952
 953
 954
 955
 956
 957
 958
 959
 960
 961
 962
 963
 964
 965
 966
 967
 968
 969
 970
 971
 972
 973
 974
 975
 976
 977
 978
 979
 980
 981
 982
 983
 984
 985
 986
 987
 988
 989
 990
 991
 992
 993
 994
 995
 996
 997
 998
 999
1000
1001
1002
1003
1004
1005
1006
1007
1008
1009
1010
1011
1012
1013
1014
1015
1016
1017
1018
1019
1020
1021
1022
1023
1024
1025
1026
1027
1028
1029
1030
1031
1032
1033
1034
1035
1036
1037
1038
1039
1040
1041
1042
1043
1044
1045
1046
1047
1048
1049
1050
1051
1052
1053
1054
1055
1056
1057
1058
1059
1060
1061
1062
1063
1064
1065
1066
1067
1068
1069
1070
1071
1072
1073
1074
1075
1076
1077
1078
1079
1080
1081
1082
1083
1084
1085
1086
1087
1088
1089
1090
1091
1092
1093
1094
1095
1096
1097
1098
1099
1100
1101
1102
1103
1104
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114
1115
1116
1117
1118
1119
1120
1121
1122
1123
1124
1125
1126
1127
1128
1129
1130
1131
1132
1133
1134
1135
1136
1137
1138
1139
1140
1141
1142
1143
1144
1145
1146
1147
1148
1149
1150
1151
1152
1153
1154
1155
1156
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
1167
1168
1169
1170
1171
1172
1173
1174
1175
1176
1177
1178
1179
1180
1181
1182
1183
1184
1185
1186
1187
1188
1189
1190
1191
1192
1193
1194
1195
1196
1197
1198
1199
1200
1201
1202
1203
1204
1205
1206
1207
1208
1209
1210
1211
1212
1213
1214
1215
1216
1217
1218
1219
1220
1221
1222
1223
1224
1225
1226
1227
1228
1229
1230
1231
1232
1233
1234
1235
1236
1237
1238
1239
1240
1241
1242
1243
1244
1245
1246
1247
1248
1249
1250
1251
1252
1253
1254
1255
1256
1257
1258
1259
1260
1261
1262
1263
1264
1265
1266
1267
1268
1269
1270
1271
1272
1273
1274
1275
1276
1277
1278
1279
1280
1281
1282
1283
1284
1285
1286
1287
1288
1289
1290
1291
1292
1293
1294
1295
1296
1297
1298
1299
1300
1301
1302
1303
1304
1305
1306
1307
1308
1309
1310
1311
1312
1313
1314
1315
1316
1317
1318
1319
1320
1321
1322
1323
1324
1325
1326
1327
1328
1329
1330
1331
1332
1333
1334
1335
1336
1337
1338
1339
1340
1341
1342
1343
1344
1345
1346
1347
1348
1349
1350
1351
1352
1353
1354
1355
1356
 
= Trace2 API

The Trace2 API can be used to print debug, performance, and telemetry
information to stderr or a file.  The Trace2 feature is inactive unless
explicitly enabled by enabling one or more Trace2 Targets.

The Trace2 API is intended to replace the existing (Trace1)
printf-style tracing provided by the existing `GIT_TRACE` and
`GIT_TRACE_PERFORMANCE` facilities.  During initial implementation,
Trace2 and Trace1 may operate in parallel.

The Trace2 API defines a set of high-level messages with known fields,
such as (`start`: `argv`) and (`exit`: {`exit-code`, `elapsed-time`}).

Trace2 instrumentation throughout the Git code base sends Trace2
messages to the enabled Trace2 Targets.  Targets transform these
messages content into purpose-specific formats and write events to
their data streams.  In this manner, the Trace2 API can drive
many different types of analysis.

Targets are defined using a VTable allowing easy extension to other
formats in the future.  This might be used to define a binary format,
for example.

== Trace2 Targets

Trace2 defines the following set of Trace2 Targets.
Format details are given in a later section.

`GIT_TR2` (NORMAL)::

	a simple printf format like GIT_TRACE.
+
------------
$ export GIT_TR2=~/log.normal
$ git version
git version 2.20.1.155.g426c96fcdb
------------
+
------------
$ cat ~/log.normal
12:28:42.620009 common-main.c:38                  version 2.20.1.155.g426c96fcdb
12:28:42.620989 common-main.c:39                  start git version
12:28:42.621101 git.c:432                         cmd_name version (version)
12:28:42.621215 git.c:662                         exit elapsed:0.001227 code:0
12:28:42.621250 trace2/tr2_tgt_normal.c:124       atexit elapsed:0.001265 code:0
------------

`GIT_TR2_PERF` (PERF)::

	a column-based format to replace GIT_TRACE_PERFORMANCE suitable for
	development and testing, possibly to complement tools like gprof.
+
------------
$ export GIT_TR2_PERF=~/log.perf
$ git version
git version 2.20.1.155.g426c96fcdb
------------
+
------------
$ cat ~/log.perf
12:28:42.620675 common-main.c:38                  | d0 | main                     | version      |     |           |           |            | 2.20.1.155.g426c96fcdb
12:28:42.621001 common-main.c:39                  | d0 | main                     | start        |     |  0.001173 |           |            | git version
12:28:42.621111 git.c:432                         | d0 | main                     | cmd_name     |     |           |           |            | version (version)
12:28:42.621225 git.c:662                         | d0 | main                     | exit         |     |  0.001227 |           |            | code:0
12:28:42.621259 trace2/tr2_tgt_perf.c:211         | d0 | main                     | atexit       |     |  0.001265 |           |            | code:0
------------

`GIT_TR2_EVENT` (EVENT)::

	a JSON-based format of event data suitable for telemetry analysis.
+
------------
$ export GIT_TR2_EVENT=~/log.event
$ git version
git version 2.20.1.155.g426c96fcdb
------------
+
------------
$ cat ~/log.event
{"event":"version","sid":"sid":"20190408T191610.507018Z-H9b68c35f-P028492","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"1","exe":"2.20.1.155.g426c96fcdb"}
{"event":"start","sid":"20190408T191610.507018Z-H9b68c35f-P028492","thread":"main","time":"2019-01-16T17:28:42.621027Z","file":"common-main.c","line":39,"t_abs":0.001173,"argv":["git","version"]}
{"event":"cmd_name","sid":"20190408T191610.507018Z-H9b68c35f-P028492","thread":"main","time":"2019-01-16T17:28:42.621122Z","file":"git.c","line":432,"name":"version","hierarchy":"version"}
{"event":"exit","sid":"20190408T191610.507018Z-H9b68c35f-P028492","thread":"main","time":"2019-01-16T17:28:42.621236Z","file":"git.c","line":662,"t_abs":0.001227,"code":0}
{"event":"atexit","sid":"20190408T191610.507018Z-H9b68c35f-P028492","thread":"main","time":"2019-01-16T17:28:42.621268Z","file":"trace2/tr2_tgt_event.c","line":163,"t_abs":0.001265,"code":0}
------------

== Enabling a Target

A Trace2 Target is enabled when the corresponding environment variable
(`GIT_TR2`, `GIT_TR2_PERF`, or `GIT_TR2_EVENT`) is set.  The following
values are recognized.

`0`::
`false`::

	Disables the target.

`1`::
`true`::

	Enables the target and writes stream to `STDERR`.

`[2-9]`::

	Enables the target and writes to the already opened file descriptor.

`<absolute-pathname>`::

	Enables the target, opens and writes to the file in append mode.

`af_unix:[<socket_type>:]<absolute-pathname>`::

	Enables the target, opens and writes to a Unix Domain Socket
	(on platforms that support them).
+
Socket type can be either `stream` or `dgram`.  If the socket type is
omitted, Git will try both.

== Trace2 API

All public Trace2 functions and macros are defined in `trace2.h` and
`trace2.c`.  All public symbols are prefixed with `trace2_`.

There are no public Trace2 data structures.

The Trace2 code also defines a set of private functions and data types
in the `trace2/` directory.  These symbols are prefixed with `tr2_`
and should only be used by functions in `trace2.c`.

== Conventions for Public Functions and Macros

The functions defined by the Trace2 API are declared and documented
in `trace2.h`.  It defines the API functions and wrapper macros for
Trace2.

Some functions have a `_fl()` suffix to indicate that they take `file`
and `line-number` arguments.

Some functions have a `_va_fl()` suffix to indicate that they also
take a `va_list` argument.

Some functions have a `_printf_fl()` suffix to indicate that they also
take a varargs argument.

There are CPP wrapper macros and ifdefs to hide most of these details.
See `trace2.h` for more details.  The following discussion will only
describe the simplified forms.

== Public API

All Trace2 API functions send a messsage to all of the active
Trace2 Targets.  This section describes the set of available
messages.

It helps to divide these functions into groups for discussion
purposes.

=== Basic Command Messages

These are concerned with the lifetime of the overall git process.

`void trace2_initialize_clock()`::

	Initialize the Trace2 start clock and nothing else.  This should
	be called at the very top of main() to capture the process start
	time and reduce startup order dependencies.

`void trace2_initialize()`::

	Determines if any Trace2 Targets should be enabled and
	initializes the Trace2 facility.  This includes setting up the
	Trace2 thread local storage (TLS).
+
This function emits a "version" message containing the version of git
and the Trace2 protocol.
+
This function should be called from `main()` as early as possible in
the life of the process after essential process initialization.

`int trace2_is_enabled()`::

	Returns 1 if Trace2 is enabled (at least one target is
	active).

`void trace2_cmd_start(int argc, const char **argv)`::

	Emits a "start" message containing the process command line
	arguments.

`int trace2_cmd_exit(int exit_code)`::

	Emits an "exit" message containing the process exit-code and
	elapsed time.
+
Returns the exit-code.

`void trace2_cmd_error(const char *fmt, va_list ap)`::

	Emits an "error" message containing a formatted error message.

`void trace2_cmd_path(const char *pathname)`::

	Emits a "cmd_path" message with the full pathname of the
	current process.

=== Command Detail Messages

These are concerned with describing the specific Git command
after the command line, config, and environment are inspected.

`void trace2_cmd_name(const char *name)`::

	Emits a "cmd_name" message with the canonical name of the
	command, for example "status" or "checkout".

`void trace2_cmd_mode(const char *mode)`::

	Emits a "cmd_mode" message with a qualifier name to further
	describe the current git command.
+
This message is intended to be used with git commands having multiple
major modes.  For example, a "checkout" command can checkout a new
branch or it can checkout a single file, so the checkout code could
emit a cmd_mode message of "branch" or "file".

`void trace2_cmd_alias(const char *alias, const char **argv_expansion)`::

	Emits an "alias" message containing the alias used and the
	argument expansion.

`void trace2_def_param(const char *parameter, const char *value)`::

	Emits a "def_param" message containing a key/value pair.
+
This message is intended to report some global aspect of the current
command, such as a configuration setting or command line switch that
significantly affects program performance or behavior, such as
`core.abbrev`, `status.showUntrackedFiles`, or `--no-ahead-behind`.

`void trace2_cmd_list_config()`::

	Emits a "def_param" messages for "important" configuration
	settings.
+
The environment variable `GIT_TR2_CONFIG_PARAMS` can be set to a
list of patterns of important configuration settings, for example:
`core.*,remote.*.url`.  This function will iterate over all config
settings and emit a "def_param" message for each match.

`void trace2_cmd_set_config(const char *key, const char *value)`::

	Emits a "def_param" message for a specific configuration
	setting IFF it matches the `GIT_TR2_CONFIG_PARAMS` pattern.
+
This is used to hook into `git_config_set()` and catch any
configuration changes and update a value previously reported by
`trace2_cmd_list_config()`.

`void trace2_def_repo(struct repository *repo)`::

	Registers a repository with the Trace2 layer.  Assigns a
	unique "repo-id" to `repo->trace2_repo_id`.
+
Emits a "worktree" messages containing the repo-id and the worktree
pathname.
+
Region and data messages (described later) may refer to this repo-id.
+
The main/top-level repository will have repo-id value 1 (aka "r1").
+
The repo-id field is in anticipation of future in-proc submodule
repositories.

=== Child Process Messages

These are concerned with the various spawned child processes,
including shell scripts, git commands, editors, pagers, and hooks.

`void trace2_child_start(struct child_process *cmd)`::

	Emits a "child_start" message containing the "child-id",
	"child-argv", and "child-classification".
+
Before calling this, set `cmd->trace2_child_class` to a name
describing the type of child process, for example "editor".
+
This function assigns a unique "child-id" to `cmd->trace2_child_id`.
This field is used later during the "child_exit" message to associate
it with the "child_start" message.
+
This function should be called before spawning the child process.

`void trace2_child_exit(struct child_proess *cmd, int child_exit_code)`::

	Emits a "child_exit" message containing the "child-id",
	the child's elapsed time and exit-code.
+
The reported elapsed time includes the process creation overhead and
time spend waiting for it to exit, so it may be slightly longer than
the time reported by the child itself.
+
This function should be called after reaping the child process.

`int trace2_exec(const char *exe, const char **argv)`::

	Emits a "exec" message containing the "exec-id" and the
	argv of the new process.
+
This function should be called before calling one of the `exec()`
variants, such as `execvp()`.
+
This function returns a unique "exec-id".  This value is used later
if the exec() fails and a "exec-result" message is necessary.

`void trace2_exec_result(int exec_id, int error_code)`::

	Emits a "exec_result" message containing the "exec-id"
	and the error code.
+
On Unix-based systems, `exec()` does not return if successful.
This message is used to indicate that the `exec()` failed and
that the current program is continuing.

=== Git Thread Messages

These messages are concerned with Git thread usage.

`void trace2_thread_start(const char *thread_name)`::

	Emits a "thread_start" message.
+
The `thread_name` field should be a descriptive name, such as the
unique name of the thread-proc.  A unique "thread-id" will be added
to the name to uniquely identify thread instances.
+
Region and data messages (described later) may refer to this thread
name.
+
This function must be called by the thread-proc of the new thread
(so that TLS data is properly initialized) and not by the caller
of `pthread_create()`.

`void trace2_thread_exit()`::

	Emits a "thread_exit" message containing the thread name
	and the thread elapsed time.
+
This function must be called by the thread-proc before it returns
(so that the coorect TLS data is used and cleaned up.  It should
not be called by the caller of `pthread_join()`.

=== Region and Data Messages

These are concerned with recording performance data
over regions or spans of code.

`void trace2_region_enter(const char *category, const char *label, const struct repository *repo)`::

`void trace2_region_enter_printf(const char *category, const char *label, const struct repository *repo, const char *fmt, ...)`::

`void trace2_region_enter_printf_va(const char *category, const char *label, const struct repository *repo, const char *fmt, va_list ap)`::

	Emits a thread-relative "region_enter" message with optional
	printf string.
+
This function pushes a new region nesting stack level on the current
thread and starts a clock for the new stack frame.
+
The `category` field is an arbitrary category name used to classify
regions by feature area, such as "status" or "index".  At this time
it is only just printed along with the rest of the message.  It may
be used in the future to filter messages.
+
The `label` field is an arbitrary label used to describe the activity
being started, such as "read_recursive" or "do_read_index".
+
The `repo` field, if set, will be used to get the "repo-id", so that
recursive oerations can be attributed to the correct repository.

`void trace2_region_leave(const char *category, const char *label, const struct repository *repo)`::

`void trace2_region_leave_printf(const char *category, const char *label, const struct repository *repo, const char *fmt, ...)`::

`void trace2_region_leave_printf_va(const char *category, const char *label, const struct repository *repo, const char *fmt, va_list ap)`::

	Emits a thread-relative "region_leave" message with optional
	printf string.
+
This function pops the region nesting stack on the current thread
and reports the elapsed time of the stack frame.
+
The `category`, `label`, and `repo` fields are the same as above.
The `category` and `label` do not need to match the correpsonding
"region_enter" message, but it makes the data stream easier to
understand.

`void trace2_data_string(const char *category, const struct repository *repo, const char *key, const char * value)`::

`void trace2_data_intmax(const char *category, const struct repository *repo, const char *key, intmax value)`::

`void trace2_data_json(const char *category, const struct repository *repo, const char *key, const struct json_writer *jw)`::

	Emits a region- and thread-relative "data" or "data_json" message.
+
This is a key/value pair message containing information about the
current thread, region stack, and repository.  This could be used
to print the number of files in a directory during a multi-threaded
recursive tree walk.

`void trace2_printf(const char *fmt, ...)`::

`void trace2_printf_va(const char *fmt, va_list ap)`::

	Emits a region- and thread-relative "printf" message.

== Trace2 Target Formats

=== NORMAL Format

NORMAL format is enabled when the `GIT_TR2` environment variable is
set.

Events are written as lines of the form:

------------
[<time> SP <filename>:<line> SP+] <event-name> [[SP] <event-message>] LF
------------

`<event-name>`::

	is the event name.

`<event-message>`::
	is a free-form printf message intended for human consumption.
+
Note that this may contain embedded LF or CRLF characters that are
not escaped, so the event may spill across multiple lines.

If `GIT_TR2_BRIEF` is true, the `time`, `filename`, and `line` fields
are omitted.

This target is intended to be more of a summary (like GIT_TRACE) and
less detailed than the other targets.  It ignores thread, region, and
data messages, for example.

=== PERF Format

PERF format is enabled when the `GIT_TR2_PERF` environment variable
is set.

Events are written as lines of the form:

------------
[<time> SP <filename>:<line> SP+
    BAR SP] d<depth> SP
    BAR SP <thread-name> SP+
    BAR SP <event-name> SP+
    BAR SP [r<repo-id>] SP+
    BAR SP [<t_abs>] SP+
    BAR SP [<t_rel>] SP+
    BAR SP [<category>] SP+
    BAR SP DOTS* <perf-event-message>
    LF
------------

`<depth>`::
	is the git process depth.  This is the number of parent
	git processes.  A top-level git command has depth value "d0".
	A child of it has depth value "d1".  A second level child
	has depth value "d2" and so on.

`<thread-name>`::
	is a unique name for the thread.  The primary thread
	is called "main".  Other thread names are of the form "th%d:%s"
	and include a unique number and the name of the thread-proc.

`<event-name>`::
	is the event name.

`<repo-id>`::
	when present, is a number indicating the repository
	in use.  A `def_repo` event is emitted when a repository is
	opened.  This defines the repo-id and associated worktree.
	Subsequent repo-specific events will reference this repo-id.
+
Currently, this is always "r1" for the main repository.
This field is in anticipation of in-proc submodules in the future.

`<t_abs>`::
	when present, is the absolute time in seconds since the
	program started.

`<t_rel>`::
	when present, is time in seconds relative to the start of
	the current region.  For a thread-exit event, it is the elapsed
	time of the thread.

`<category>`::
	is present on region and data events and is used to
	indicate a broad category, such as "index" or "status".

`<perf-event-message>`::
	is a free-form printf message intended for human consumption.

------------
15:33:33.532712 wt-status.c:2310                  | d0 | main                     | region_enter | r1  |  0.126064 |           | status     | label:print
15:33:33.532712 wt-status.c:2331                  | d0 | main                     | region_leave | r1  |  0.127568 |  0.001504 | status     | label:print
------------

If `GIT_TR2_PERF_BRIEF` is true, the `time`, `file`, and `line`
fields are omitted.

------------
d0 | main                     | region_leave | r1  |  0.011717 |  0.009122 | index      | label:preload
------------

The PERF target is intended for interactive performance analysis
during development and is quite noisy.

=== EVENT Format

EVENT format is enabled when the `GIT_TR2_EVENT` environment
variable is set.

Each event is a JSON-object containing multiple key/value pairs
written as a single line and followed by a LF.

------------
'{' <key> ':' <value> [',' <key> ':' <value>]* '}' LF
------------

Some key/value pairs are common to all events and some are
event-specific.

==== Common Key/Value Pairs

The following key/value pairs are common to all events:

------------
{
	"event":"version",
	"sid":"20190408T191827.272759Z-H9b68c35f-P011764",
	"thread":"main",
	"time":"2019-04-08T19:18:27.282761Z",
	"file":"common-main.c",
	"line":42,
	...
}
------------

`"event":<event>`::
	is the event name.

`"sid":<sid>`::
	is the session-id.  This is a unique string to identify the
	process instance to allow all events emitted by a process to
	be identified.  A session-id is used instead of a PID because
	PIDs are recycled by the OS.  For child git processes, the
	session-id is prepended with the session-id of the parent git
	process to allow parent-child relationships to be identified
	during post-processing.

`"thread":<thread>`::
	is the thread name.

`"time":<time>`::
	is the UTC time of the event.

`"file":<filename>`::
	is source file generating the event.

`"line":<line-number>`::
	is the integer source line number generating the event.

`"repo":<repo-id>`::
	when present, is the integer repo-id as described previously.

If `GIT_TR2_EVENT_BRIEF` is true, the `file` and `line` fields are omitted
from all events and the `time` field is only present on the "start" and
"atexit" events.

==== Event-Specific Key/Value Pairs

`"version"`::
	This event gives the version of the executable and the EVENT format.
+
------------
{
	"event":"version",
	...
	"evt":"1",		       # EVENT format version
	"exe":"2.20.1.155.g426c96fcdb" # git version
}
------------

`"start"`::
	This event contains the complete argv received by main().
+
------------
{
	"event":"start",
	...
	"t_abs":0.001227, # elapsed time in seconds
	"argv":["git","version"]
}
------------

`"exit"`::
	This event is emitted when git calls `exit()`.
+
------------
{
	"event":"exit",
	...
	"t_abs":0.001227, # elapsed time in seconds
	"code":0	  # exit code
}
------------

`"atexit"`::
	This event is emitted by the Trace2 `atexit` routine during
	final shutdown.  It should be the last event emitted by the
	process.
+
(The elapsed time reported here is greater than the time reported in
the "exit" event because it runs after all other atexit tasks have
completed.)
+
------------
{
	"event":"atexit",
	...
	"t_abs":0.001227, # elapsed time in seconds
	"code":0          # exit code
}
------------

`"signal"`::
	This event is emitted when the program is terminated by a user
	signal.  Depending on the platform, the signal event may
	prevent the "atexit" event from being generated.
+
------------
{
	"event":"signal",
	...
	"t_abs":0.001227,  # elapsed time in seconds
	"signal":13        # SIGTERM, SIGINT, etc.
}
------------

`"error"`::
	This event is emitted when one of the `error()`, `die()`,
	or `usage()` functions are called.
+
------------
{
	"event":"error",
	...
	"msg":"invalid option: --cahced", # formatted error message
	"fmt":"invalid option: %s"	  # error format string
}
------------
+
The error event may be emitted more than once.  The format string
allows post-processors to group errors by type without worrying
about specific error arguments.

`"cmd_path"`::
	This event contains the discovered full path of the git
	executable (on platforms that are configured to resolve it).
+
------------
{
	"event":"cmd_path",
	...
	"path":"C:/work/gfw/git.exe"
}
------------

`"cmd_name"`::
	This event contains the command name for this git process
	and the hierarchy of commands from parent git processes.
+
------------
{
	"event":"cmd_name",
	...
	"name":"pack-objects",
	"hierarchy":"push/pack-objects"
}
------------
+
Normally, the "name" field contains the canonical name of the
command.  When a canonical name is not available, one of
these special values are used:
+
------------
"_query_"            # "git --html-path"
"_run_dashed_"       # when "git foo" tries to run "git-foo"
"_run_shell_alias_"  # alias expansion to a shell command
"_run_git_alias_"    # alias expansion to a git command
"_usage_"            # usage error
------------

`"cmd_mode"`::
	This event, when present, describes the command variant This
	event may be emitted more than once.
+
------------
{
	"event":"cmd_mode",
	...
	"name":"branch"
}
------------
+
The "name" field is an arbitrary string to describe the command mode.
For example, checkout can checkout a branch or an individual file.
And these variations typically have different performance
characteristics that are not comparable.

`"alias"`::
	This event is present when an alias is expanded.
+
------------
{
	"event":"alias",
	...
	"alias":"l",		 # registered alias
	"argv":["log","--graph"] # alias expansion
}
------------

`"child_start"`::
	This event describes a child process that is about to be
	spawned.
+
------------
{
	"event":"child_start",
	...
	"child_id":2,
	"child_class":"?",
	"use_shell":false,
	"argv":["git","rev-list","--objects","--stdin","--not","--all","--quiet"]

	"hook_name":"<hook_name>"  # present when child_class is "hook"
	"cd":"<path>"		   # present when cd is required
}
------------
+
The "child_id" field can be used to match this child_start with the
corresponding child_exit event.
+
The "child_class" field is a rough classification, such as "editor",
"pager", "transport/*", and "hook".  Unclassified children are classified
with "?".

`"child_exit"`::
	This event is generated after the current process has returned
	from the waitpid() and collected the exit information from the
	child.
+
------------
{
	"event":"child_exit",
	...
	"child_id":2,
	"pid":14708,	 # child PID
	"code":0,	 # child exit-code
	"t_rel":0.110605 # observed run-time of child process
}
------------
+
Note that the session-id of the child process is not available to
the current/spawning process, so the child's PID is reported here as
a hint for post-processing.  (But it is only a hint because the child
proces may be a shell script which doesn't have a session-id.)
+
Note that the `t_rel` field contains the observed run time in seconds
for the child process (starting before the fork/exec/spawn and
stopping after the waitpid() and includes OS process creation overhead).
So this time will be slightly larger than the atexit time reported by
the child process itself.

`"exec"`::
	This event is generated before git attempts to `exec()`
	another command rather than starting a child process.
+
------------
{
	"event":"exec",
	...
	"exec_id":0,
	"exe":"git",
	"argv":["foo", "bar"]
}
------------
+
The "exec_id" field is a command-unique id and is only useful if the
`exec()` fails and a corresponding exec_result event is generated.

`"exec_result"`::
	This event is generated if the `exec()` fails and control
	returns to the current git command.
+
------------
{
	"event":"exec_result",
	...
	"exec_id":0,
	"code":1      # error code (errno) from exec()
}
------------

`"thread_start"`::
	This event is generated when a thread is started.  It is
	generated from *within* the new thread's thread-proc (for TLS
	reasons).
+
------------
{
	"event":"thread_start",
	...
	"thread":"th02:preload_thread" # thread name
}
------------

`"thread_exit"`::
	This event is generated when a thread exits.  It is generated
	from *within* the thread's thread-proc (for TLS reasons).
+
------------
{
	"event":"thread_exit",
	...
	"thread":"th02:preload_thread", # thread name
	"t_rel":0.007328                # thread elapsed time
}
------------

`"def_param"`::
	This event is generated to log a global parameter.
+
------------
{
	"event":"def_param",
	...
	"param":"core.abbrev",
	"value":"7"
}
------------

`"def_repo"`::
	This event defines a repo-id and associates it with the root
	of the worktree.
+
------------
{
	"event":"def_repo",
	...
	"repo":1,
	"worktree":"/Users/jeffhost/work/gfw"
}
------------
+
As stated earlier, the repo-id is currently always 1, so there will
only be one def_repo event.  Later, if in-proc submodules are
supported, a def_repo event should be emitted for each submodule
visited.

`"region_enter"`::
	This event is generated when entering a region.
+
------------
{
	"event":"region_enter",
	...
	"repo":1,                # optional
	"nesting":1,             # current region stack depth
	"category":"index",      # optional
	"label":"do_read_index", # optional
	"msg":".git/index"       # optional
}
------------
+
The `category` field may be used in a future enhancement to
do category-based filtering.
+
The `GIT_TR2_EVENT_NESTING` environment variable can be used to
filter deeply nested regions and data events.  It defaults to "2".

`"region_leave"`::
	This event is generated when leaving a region.
+
------------
{
	"event":"region_leave",
	...
	"repo":1,                # optional
	"t_rel":0.002876,        # time spent in region in seconds
	"nesting":1,             # region stack depth
	"category":"index",      # optional
	"label":"do_read_index", # optional
	"msg":".git/index"       # optional
}
------------

`"data"`::
	This event is generated to log a thread- and region-local
	key/value pair.
+
------------
{
	"event":"data",
	...
	"repo":1,              # optional
	"t_abs":0.024107,      # absolute elapsed time
	"t_rel":0.001031,      # elapsed time in region/thread
	"nesting":2,           # region stack depth
	"category":"index",
	"key":"read/cache_nr",
	"value":"3552"
}
------------
+
The "value" field may be an integer or a string.

`"data-json"`::
	This event is generated to log a pre-formatted JSON string
	containing structured data.
+
------------
{
	"event":"data_json",
	...
	"repo":1,              # optional
	"t_abs":0.015905,
	"t_rel":0.015905,
	"nesting":1,
	"category":"process",
	"key":"windows/ancestry",
	"value":["bash.exe","bash.exe"]
}
------------

== Example Trace2 API Usage

Here is a hypothetical usage of the Trace2 API showing the intended
usage (without worrying about the actual Git details).

Initialization::

	Initialization happens in `main()`.  Behind the scenes, an
	`atexit` and `signal` handler are registered.
+
----------------
int main(int argc, const char **argv)
{
	int exit_code;

	trace2_initialize();
	trace2_cmd_start(argv);

	exit_code = cmd_main(argc, argv);

	trace2_cmd_exit(exit_code);

	return exit_code;
}
----------------

Command Details::

	After the basics are established, additional command
	information can be sent to Trace2 as it is discovered.
+
----------------
int cmd_checkout(int argc, const char **argv)
{
	trace2_cmd_name("checkout");
	trace2_cmd_mode("branch");
	trace2_def_repo(the_repository);

	// emit "def_param" messages for "interesting" config settings.
	trace2_cmd_list_config();

	if (do_something())
	    trace2_cmd_error("Path '%s': cannot do something", path);

	return 0;
}
----------------

Child Processes::

	Wrap code spawning child processes.
+
----------------
void run_child(...)
{
	int child_exit_code;
	struct child_process cmd = CHILD_PROCESS_INIT;
	...
	cmd.trace2_child_class = "editor";

	trace2_child_start(&cmd);
	child_exit_code = spawn_child_and_wait_for_it();
	trace2_child_exit(&cmd, child_exit_code);
}
----------------
+
For example, the following fetch command spawned ssh, index-pack,
rev-list, and gc.  This example also shows that fetch took
5.199 seconds and of that 4.932 was in ssh.
+
----------------
$ export GIT_TR2_BRIEF=1
$ export GIT_TR2=~/log.normal
$ git fetch origin
...
----------------
+
----------------
$ cat ~/log.normal
version 2.20.1.vfs.1.1.47.g534dbe1ad1
start git fetch origin
worktree /Users/jeffhost/work/gfw
cmd_name fetch (fetch)
child_start[0] ssh git@github.com ...
child_start[1] git index-pack ...
... (Trace2 events from child processes omitted)
child_exit[1] pid:14707 code:0 elapsed:0.076353
child_exit[0] pid:14706 code:0 elapsed:4.931869
child_start[2] git rev-list ...
... (Trace2 events from child process omitted)
child_exit[2] pid:14708 code:0 elapsed:0.110605
child_start[3] git gc --auto
... (Trace2 events from child process omitted)
child_exit[3] pid:14709 code:0 elapsed:0.006240
exit elapsed:5.198503 code:0
atexit elapsed:5.198541 code:0
----------------
+
When a git process is a (direct or indirect) child of another
git process, it inherits Trace2 context information.  This
allows the child to print the command hierarchy.  This example
shows gc as child[3] of fetch.  When the gc process reports
its name as "gc", it also reports the hierarchy as "fetch/gc".
(In this example, trace2 messages from the child process is
indented for clarity.)
+
----------------
$ export GIT_TR2_BRIEF=1
$ export GIT_TR2=~/log.normal
$ git fetch origin
...
----------------
+
----------------
$ cat ~/log.normal
version 2.20.1.160.g5676107ecd.dirty
start git fetch official
worktree /Users/jeffhost/work/gfw
cmd_name fetch (fetch)
...
child_start[3] git gc --auto
    version 2.20.1.160.g5676107ecd.dirty
    start /Users/jeffhost/work/gfw/git gc --auto
    worktree /Users/jeffhost/work/gfw
    cmd_name gc (fetch/gc)
    exit elapsed:0.001959 code:0
    atexit elapsed:0.001997 code:0
child_exit[3] pid:20303 code:0 elapsed:0.007564
exit elapsed:3.868938 code:0
atexit elapsed:3.868970 code:0
----------------

Regions::

	Regions can be use to time an interesting section of code.
+
----------------
void wt_status_collect(struct wt_status *s)
{
	trace2_region_enter("status", "worktrees", s->repo);
	wt_status_collect_changes_worktree(s);
	trace2_region_leave("status", "worktrees", s->repo);

	trace2_region_enter("status", "index", s->repo);
	wt_status_collect_changes_index(s);
	trace2_region_leave("status", "index", s->repo);

	trace2_region_enter("status", "untracked", s->repo);
	wt_status_collect_untracked(s);
	trace2_region_leave("status", "untracked", s->repo);
}

void wt_status_print(struct wt_status *s)
{
	trace2_region_enter("status", "print", s->repo);
	switch (s->status_format) {
	    ...
	}
	trace2_region_leave("status", "print", s->repo);
}
----------------
+
In this example, scanning for untracked files ran from +0.012568 to
+0.027149 (since the process started) and took 0.014581 seconds.
+
----------------
$ export GIT_TR2_PERF_BRIEF=1
$ export GIT_TR2_PERF=~/log.perf
$ git status
...

$ cat ~/log.perf
d0 | main                     | version      |     |           |           |            | 2.20.1.160.g5676107ecd.dirty
d0 | main                     | start        |     |  0.001173 |           |            | git status
d0 | main                     | def_repo     | r1  |           |           |            | worktree:/Users/jeffhost/work/gfw
d0 | main                     | cmd_name     |     |           |           |            | status (status)
...
d0 | main                     | region_enter | r1  |  0.010988 |           | status     | label:worktrees
d0 | main                     | region_leave | r1  |  0.011236 |  0.000248 | status     | label:worktrees
d0 | main                     | region_enter | r1  |  0.011260 |           | status     | label:index
d0 | main                     | region_leave | r1  |  0.012542 |  0.001282 | status     | label:index
d0 | main                     | region_enter | r1  |  0.012568 |           | status     | label:untracked
d0 | main                     | region_leave | r1  |  0.027149 |  0.014581 | status     | label:untracked
d0 | main                     | region_enter | r1  |  0.027411 |           | status     | label:print
d0 | main                     | region_leave | r1  |  0.028741 |  0.001330 | status     | label:print
d0 | main                     | exit         |     |  0.028778 |           |            | code:0
d0 | main                     | atexit       |     |  0.028809 |           |            | code:0
----------------
+
Regions may be nested.  This causes messages to be indented in the
PERF target, for example.
Elapsed times are relative to the start of the correpsonding nesting
level as expected.  For example, if we add region message to:
+
----------------
static enum path_treatment read_directory_recursive(struct dir_struct *dir,
	struct index_state *istate, const char *base, int baselen,
	struct untracked_cache_dir *untracked, int check_only,
	int stop_at_first_file, const struct pathspec *pathspec)
{
	enum path_treatment state, subdir_state, dir_state = path_none;

	trace2_region_enter_printf("dir", "read_recursive", NULL, "%.*s", baselen, base);
	...
	trace2_region_leave_printf("dir", "read_recursive", NULL, "%.*s", baselen, base);
	return dir_state;
}
----------------
+
We can further investigate the time spent scanning for untracked files.
+
----------------
$ export GIT_TR2_PERF_BRIEF=1
$ export GIT_TR2_PERF=~/log.perf
$ git status
...
$ cat ~/log.perf
d0 | main                     | version      |     |           |           |            | 2.20.1.162.gb4ccea44db.dirty
d0 | main                     | start        |     |  0.001173 |           |            | git status
d0 | main                     | def_repo     | r1  |           |           |            | worktree:/Users/jeffhost/work/gfw
d0 | main                     | cmd_name     |     |           |           |            | status (status)
...
d0 | main                     | region_enter | r1  |  0.015047 |           | status     | label:untracked
d0 | main                     | region_enter |     |  0.015132 |           | dir        | ..label:read_recursive
d0 | main                     | region_enter |     |  0.016341 |           | dir        | ....label:read_recursive vcs-svn/
d0 | main                     | region_leave |     |  0.016422 |  0.000081 | dir        | ....label:read_recursive vcs-svn/
d0 | main                     | region_enter |     |  0.016446 |           | dir        | ....label:read_recursive xdiff/
d0 | main                     | region_leave |     |  0.016522 |  0.000076 | dir        | ....label:read_recursive xdiff/
d0 | main                     | region_enter |     |  0.016612 |           | dir        | ....label:read_recursive git-gui/
d0 | main                     | region_enter |     |  0.016698 |           | dir        | ......label:read_recursive git-gui/po/
d0 | main                     | region_enter |     |  0.016810 |           | dir        | ........label:read_recursive git-gui/po/glossary/
d0 | main                     | region_leave |     |  0.016863 |  0.000053 | dir        | ........label:read_recursive git-gui/po/glossary/
...
d0 | main                     | region_enter |     |  0.031876 |           | dir        | ....label:read_recursive builtin/
d0 | main                     | region_leave |     |  0.032270 |  0.000394 | dir        | ....label:read_recursive builtin/
d0 | main                     | region_leave |     |  0.032414 |  0.017282 | dir        | ..label:read_recursive
d0 | main                     | region_leave | r1  |  0.032454 |  0.017407 | status     | label:untracked
...
d0 | main                     | exit         |     |  0.034279 |           |            | code:0
d0 | main                     | atexit       |     |  0.034322 |           |            | code:0
----------------
+
Trace2 regions are similar to the existing trace_performance_enter()
and trace_performance_leave() routines, but are thread safe and
maintain per-thread stacks of timers.

Data Messages::

	Data messages added to a region.
+
----------------
int read_index_from(struct index_state *istate, const char *path,
	const char *gitdir)
{
	trace2_region_enter_printf("index", "do_read_index", the_repository, "%s", path);

	...

	trace2_data_intmax("index", the_repository, "read/version", istate->version);
	trace2_data_intmax("index", the_repository, "read/cache_nr", istate->cache_nr);

	trace2_region_leave_printf("index", "do_read_index", the_repository, "%s", path);
}
----------------
+
This example shows that the index contained 3552 entries.
+
----------------
$ export GIT_TR2_PERF_BRIEF=1
$ export GIT_TR2_PERF=~/log.perf
$ git status
...
$ cat ~/log.perf
d0 | main                     | version      |     |           |           |            | 2.20.1.156.gf9916ae094.dirty
d0 | main                     | start        |     |  0.001173 |           |            | git status
d0 | main                     | def_repo     | r1  |           |           |            | worktree:/Users/jeffhost/work/gfw
d0 | main                     | cmd_name     |     |           |           |            | status (status)
d0 | main                     | region_enter | r1  |  0.001791 |           | index      | label:do_read_index .git/index
d0 | main                     | data         | r1  |  0.002494 |  0.000703 | index      | ..read/version:2
d0 | main                     | data         | r1  |  0.002520 |  0.000729 | index      | ..read/cache_nr:3552
d0 | main                     | region_leave | r1  |  0.002539 |  0.000748 | index      | label:do_read_index .git/index
...
----------------

Thread Events::

	Thread messages added to a thread-proc.
+
For example, the multithreaded preload-index code can be
instrumented with a region around the thread pool and then
per-thread start and exit events within the threadproc.
+
----------------
static void *preload_thread(void *_data)
{
	// start the per-thread clock and emit a message.
	trace2_thread_start("preload_thread");

	// report which chunk of the array this thread was assigned.
	trace2_data_intmax("index", the_repository, "offset", p->offset);
	trace2_data_intmax("index", the_repository, "count", nr);

	do {
	    ...
	} while (--nr > 0);
	...

	// report elapsed time taken by this thread.
	trace2_thread_exit();
	return NULL;
}

void preload_index(struct index_state *index,
	const struct pathspec *pathspec,
	unsigned int refresh_flags)
{
	trace2_region_enter("index", "preload", the_repository);

	for (i = 0; i < threads; i++) {
	    ... /* create thread */
	}

	for (i = 0; i < threads; i++) {
	    ... /* join thread */
	}

	trace2_region_leave("index", "preload", the_repository);
}
----------------
+
In this example preload_index() was executed by the `main` thread
and started the `preload` region.  Seven threads, named
`th01:preload_thread` through `th07:preload_thread`, were started.
Events from each thread are atomically appended to the shared target
stream as they occur so they may appear in random order with respect
other threads. Finally, the main thread waits for the threads to
finish and leaves the region.
+
Data events are tagged with the active thread name.  They are used
to report the per-thread parameters.
+
----------------
$ export GIT_TR2_PERF_BRIEF=1
$ export GIT_TR2_PERF=~/log.perf
$ git status
...
$ cat ~/log.perf
...
d0 | main                     | region_enter | r1  |  0.002595 |           | index      | label:preload
d0 | th01:preload_thread      | thread_start |     |  0.002699 |           |            |
d0 | th02:preload_thread      | thread_start |     |  0.002721 |           |            |
d0 | th01:preload_thread      | data         | r1  |  0.002736 |  0.000037 | index      | offset:0
d0 | th02:preload_thread      | data         | r1  |  0.002751 |  0.000030 | index      | offset:2032
d0 | th03:preload_thread      | thread_start |     |  0.002711 |           |            |
d0 | th06:preload_thread      | thread_start |     |  0.002739 |           |            |
d0 | th01:preload_thread      | data         | r1  |  0.002766 |  0.000067 | index      | count:508
d0 | th06:preload_thread      | data         | r1  |  0.002856 |  0.000117 | index      | offset:2540
d0 | th03:preload_thread      | data         | r1  |  0.002824 |  0.000113 | index      | offset:1016
d0 | th04:preload_thread      | thread_start |     |  0.002710 |           |            |
d0 | th02:preload_thread      | data         | r1  |  0.002779 |  0.000058 | index      | count:508
d0 | th06:preload_thread      | data         | r1  |  0.002966 |  0.000227 | index      | count:508
d0 | th07:preload_thread      | thread_start |     |  0.002741 |           |            |
d0 | th07:preload_thread      | data         | r1  |  0.003017 |  0.000276 | index      | offset:3048
d0 | th05:preload_thread      | thread_start |     |  0.002712 |           |            |
d0 | th05:preload_thread      | data         | r1  |  0.003067 |  0.000355 | index      | offset:1524
d0 | th05:preload_thread      | data         | r1  |  0.003090 |  0.000378 | index      | count:508
d0 | th07:preload_thread      | data         | r1  |  0.003037 |  0.000296 | index      | count:504
d0 | th03:preload_thread      | data         | r1  |  0.002971 |  0.000260 | index      | count:508
d0 | th04:preload_thread      | data         | r1  |  0.002983 |  0.000273 | index      | offset:508
d0 | th04:preload_thread      | data         | r1  |  0.007311 |  0.004601 | index      | count:508
d0 | th05:preload_thread      | thread_exit  |     |  0.008781 |  0.006069 |            |
d0 | th01:preload_thread      | thread_exit  |     |  0.009561 |  0.006862 |            |
d0 | th03:preload_thread      | thread_exit  |     |  0.009742 |  0.007031 |            |
d0 | th06:preload_thread      | thread_exit  |     |  0.009820 |  0.007081 |            |
d0 | th02:preload_thread      | thread_exit  |     |  0.010274 |  0.007553 |            |
d0 | th07:preload_thread      | thread_exit  |     |  0.010477 |  0.007736 |            |
d0 | th04:preload_thread      | thread_exit  |     |  0.011657 |  0.008947 |            |
d0 | main                     | region_leave | r1  |  0.011717 |  0.009122 | index      | label:preload
...
d0 | main                     | exit         |     |  0.029996 |           |            | code:0
d0 | main                     | atexit       |     |  0.030027 |           |            | code:0
----------------
+
In this example, the preload region took 0.009122 seconds.  The 7 threads
took between 0.006069 and 0.008947 seconds to work on their portion of
the index.  Thread "th01" worked on 508 items at offset 0.  Thread "th02"
worked on 508 items at offset 2032.  Thread "th04" worked on 508 itemts
at offset 508.
+
This example also shows that thread names are assigned in a racy manner
as each thread starts and allocates TLS storage.

== Future Work

=== Relationship to the Existing Trace Api (api-trace.txt)

There are a few issues to resolve before we can completely
switch to Trace2.

* Updating existing tests that assume GIT_TRACE format messages.

* How to best handle custom GIT_TRACE_<key> messages?

** The GIT_TRACE_<key> mechanism allows each <key> to write to a
different file (in addition to just stderr).

** Do we want to maintain that ability or simply write to the existing
Trace2 targets (and convert <key> to a "category").
debug log:

solving 43adbf00eb ...
found 43adbf00eb in https://80x24.org/mirrors/git.git

git@vger.kernel.org list mirror (unofficial, one of many)

Archives are clonable:
	git clone --mirror https://public-inbox.org/git
	git clone --mirror http://ou63pmih66umazou.onion/git
	git clone --mirror http://czquwvybam4bgbro.onion/git
	git clone --mirror http://hjrcffqmbrq6wope.onion/git

Newsgroups are available over NNTP:
	nntp://news.public-inbox.org/inbox.comp.version-control.git
	nntp://ou63pmih66umazou.onion/inbox.comp.version-control.git
	nntp://czquwvybam4bgbro.onion/inbox.comp.version-control.git
	nntp://hjrcffqmbrq6wope.onion/inbox.comp.version-control.git
	nntp://news.gmane.org/gmane.comp.version-control.git

 note: .onion URLs require Tor: https://www.torproject.org/

AGPL code for this site: git clone https://public-inbox.org/ public-inbox