[thirdparty/git.git] / t / t0212-trace2-event.sh

#!/bin/sh

test_description='test trace2 facility'
. ./test-lib.sh

# Turn off any inherited trace2 settings for this test.
sane_unset GIT_TRACE2 GIT_TRACE2_PERF GIT_TRACE2_EVENT
sane_unset GIT_TRACE2_BARE
sane_unset GIT_TRACE2_CONFIG_PARAMS

perl -MJSON::PP -e 0 >/dev/null 2>&1 && test_set_prereq JSON_PP

# Add t/helper directory to PATH so that we can use a relative
# path to run nested instances of test-tool.exe (see 004child).
# This helps with HEREDOC comparisons later.
TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
PATH="$TTDIR:$PATH" && export PATH

# Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
# Warning: to do the actual diff/comparison, so the HEREDOCs here
# Warning: only cover our actual calls to test-tool and/or git.
# Warning: So you may see extra lines in artifact files when
# Warning: interactively debugging.

V=$(git version | sed -e 's/^git version //') && export V

# There are multiple trace2 targets: normal, perf, and event.
# Trace2 events will/can be written to each active target (subject
# to whatever filtering that target decides to do).
# Test each target independently.
#
# Defer setting GIT_TRACE2_PERF until the actual command we want to
# test because hidden git and test-tool commands in the test
# harness can contaminate our output.

# We don't bother repeating the 001return and 002exit tests, since they
# have coverage in the normal and perf targets.

# Verb 003error
#
# To the above, add multiple 'error <msg>' events

test_expect_success JSON_PP 'event stream, error event' '
	test_when_finished "rm trace.event actual expect" &&
	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 003error "hello world" "this is a test" &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "003error",
	|      "hello world",
	|      "this is a test"
	|    ],
	|    "errors":[
	|      "%s",
	|      "%s"
	|    ],
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

# Verb 004child
#
# Test nested spawning of child processes.
#
# Conceptually, this looks like:
#    P1: TT trace2 004child
#    P2: |--- TT trace2 004child
#    P3:      |--- TT trace2 001return 0

test_expect_success JSON_PP 'event stream, return code 0' '
	test_when_finished "rm trace.event actual expect" &&
	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 004child test-tool trace2 004child test-tool trace2 001return 0 &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "004child",
	|      "test-tool",
	|      "trace2",
	|      "004child",
	|      "test-tool",
	|      "trace2",
	|      "001return",
	|      "0"
	|    ],
	|    "child":{
	|      "0":{
	|        "child_argv":[
	|          "_EXE_",
	|          "trace2",
	|          "004child",
	|          "test-tool",
	|          "trace2",
	|          "001return",
	|          "0"
	|        ],
	|        "child_class":"?",
	|        "child_code":0,
	|        "use_shell":0
	|      }
	|    },
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  },
	|  "_SID0_/_SID1_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "004child",
	|      "test-tool",
	|      "trace2",
	|      "001return",
	|      "0"
	|    ],
	|    "child":{
	|      "0":{
	|        "child_argv":[
	|          "_EXE_",
	|          "trace2",
	|          "001return",
	|          "0"
	|        ],
	|        "child_class":"?",
	|        "child_code":0,
	|        "use_shell":0
	|      }
	|    },
	|    "exit_code":0,
	|    "hierarchy":"trace2/trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  },
	|  "_SID0_/_SID1_/_SID2_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "001return",
	|      "0"
	|    ],
	|    "exit_code":0,
	|    "hierarchy":"trace2/trace2/trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

# Test listing of all "interesting" config settings.

test_expect_success JSON_PP 'event stream, list config' '
	test_when_finished "rm trace.event actual expect" &&
	git config --local t0212.abc 1 &&
	git config --local t0212.def "hello world" &&
	GIT_TRACE2_EVENT="$(pwd)/trace.event" GIT_TRACE2_CONFIG_PARAMS="t0212.*" test-tool trace2 001return 0 &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "001return",
	|      "0"
	|    ],
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "params":[
	|      {
	|        "param":"t0212.abc",
	|        "value":"1"
	|      },
	|      {
	|        "param":"t0212.def",
	|        "value":"hello world"
	|      }
	|    ],
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

# Test listing of all "interesting" environment variables.

test_expect_success JSON_PP 'event stream, list env vars' '
	test_when_finished "rm trace.event actual expect" &&
	GIT_TRACE2_EVENT="$(pwd)/trace.event" \
		GIT_TRACE2_ENV_VARS="A_VAR,OTHER_VAR,MISSING" \
		A_VAR=1 OTHER_VAR="hello world" test-tool trace2 001return 0 &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "001return",
	|      "0"
	|    ],
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "params":[
	|      {
	|        "param":"A_VAR",
	|        "value":"1"
	|      },
	|      {
	|        "param":"OTHER_VAR",
	|        "value":"hello world"
	|      }
	|    ],
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

test_expect_success JSON_PP 'basic trace2_data' '
	test_when_finished "rm trace.event actual expect" &&
	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 006data test_category k1 v1 test_category k2 v2 &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "006data",
	|      "test_category",
	|      "k1",
	|      "v1",
	|      "test_category",
	|      "k2",
	|      "v2"
	|    ],
	|    "data":{
	|      "test_category":{
	|        "k1":"v1",
	|        "k2":"v2"
	|      }
	|    },
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

# Now test without environment variables and get all Trace2 settings
# from the global config.

test_expect_success JSON_PP 'using global config, event stream, error event' '
	test_when_finished "rm trace.event actual expect" &&
	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
	test-tool trace2 003error "hello world" "this is a test" &&
	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	sed -e "s/^|//" >expect <<-EOF &&
	|VAR1 = {
	|  "_SID0_":{
	|    "argv":[
	|      "_EXE_",
	|      "trace2",
	|      "003error",
	|      "hello world",
	|      "this is a test"
	|    ],
	|    "errors":[
	|      "%s",
	|      "%s"
	|    ],
	|    "exit_code":0,
	|    "hierarchy":"trace2",
	|    "name":"trace2",
	|    "version":"$V"
	|  }
	|};
	EOF
	test_cmp expect actual
'

test_expect_success 'discard traces when there are too many files' '
	mkdir trace_target_dir &&
	test_when_finished "rm -r trace_target_dir" &&
	(
		GIT_TRACE2_MAX_FILES=5 &&
		export GIT_TRACE2_MAX_FILES &&
		cd trace_target_dir &&
		test_seq $GIT_TRACE2_MAX_FILES >../expected_filenames.txt &&
		xargs touch <../expected_filenames.txt &&
		cd .. &&
		GIT_TRACE2_EVENT="$(pwd)/trace_target_dir" test-tool trace2 001return 0
	) &&
	echo git-trace2-discard >>expected_filenames.txt &&
	ls trace_target_dir >ls_output.txt &&
	test_cmp expected_filenames.txt ls_output.txt &&
	head -n1 trace_target_dir/git-trace2-discard | grep \"event\":\"version\" &&
	head -n2 trace_target_dir/git-trace2-discard | tail -n1 | grep \"event\":\"too_many_files\"
'

test_done
Commit	Line	Data
a15860dc JH	1	#!/bin/sh
	2
	3	test_description='test trace2 facility'
	4	. ./test-lib.sh
	5
bce9db6d	6	# Turn off any inherited trace2 settings for this test.
e4b75d6a SG	7	sane_unset GIT_TRACE2 GIT_TRACE2_PERF GIT_TRACE2_EVENT
	8	sane_unset GIT_TRACE2_BARE
	9	sane_unset GIT_TRACE2_CONFIG_PARAMS
bce9db6d	10
a15860dc JH	11	perl -MJSON::PP -e 0 >/dev/null 2>&1 && test_set_prereq JSON_PP
	12
	13	# Add t/helper directory to PATH so that we can use a relative
	14	# path to run nested instances of test-tool.exe (see 004child).
	15	# This helps with HEREDOC comparisons later.
	16	TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
	17	PATH="$TTDIR:$PATH" && export PATH
	18
	19	# Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
	20	# Warning: to do the actual diff/comparison, so the HEREDOCs here
	21	# Warning: only cover our actual calls to test-tool and/or git.
	22	# Warning: So you may see extra lines in artifact files when
	23	# Warning: interactively debugging.
	24
a15860dc JH	25	V=$(git version \| sed -e 's/^git version //') && export V
	26
	27	# There are multiple trace2 targets: normal, perf, and event.
	28	# Trace2 events will/can be written to each active target (subject
	29	# to whatever filtering that target decides to do).
	30	# Test each target independently.
	31	#
e4b75d6a	32	# Defer setting GIT_TRACE2_PERF until the actual command we want to
a15860dc JH	33	# test because hidden git and test-tool commands in the test
	34	# harness can contaminate our output.
	35
	36	# We don't bother repeating the 001return and 002exit tests, since they
	37	# have coverage in the normal and perf targets.
	38
	39	# Verb 003error
	40	#
	41	# To the above, add multiple 'error <msg>' events
	42
	43	test_expect_success JSON_PP 'event stream, error event' '
	44	test_when_finished "rm trace.event actual expect" &&
e4b75d6a	45	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 003error "hello world" "this is a test" &&
a15860dc JH	46	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	47	sed -e "s/^\|//" >expect <<-EOF &&
	48	\|VAR1 = {
	49	\| "_SID0_":{
	50	\| "argv":[
	51	\| "_EXE_",
	52	\| "trace2",
	53	\| "003error",
	54	\| "hello world",
	55	\| "this is a test"
	56	\| ],
	57	\| "errors":[
	58	\| "%s",
	59	\| "%s"
	60	\| ],
	61	\| "exit_code":0,
	62	\| "hierarchy":"trace2",
	63	\| "name":"trace2",
	64	\| "version":"$V"
	65	\| }
	66	\|};
	67	EOF
	68	test_cmp expect actual
	69	'
	70
	71	# Verb 004child
	72	#
	73	# Test nested spawning of child processes.
	74	#
	75	# Conceptually, this looks like:
	76	# P1: TT trace2 004child
	77	# P2: \|--- TT trace2 004child
	78	# P3: \|--- TT trace2 001return 0
	79
	80	test_expect_success JSON_PP 'event stream, return code 0' '
	81	test_when_finished "rm trace.event actual expect" &&
e4b75d6a	82	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 004child test-tool trace2 004child test-tool trace2 001return 0 &&
a15860dc JH	83	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	84	sed -e "s/^\|//" >expect <<-EOF &&
	85	\|VAR1 = {
	86	\| "_SID0_":{
	87	\| "argv":[
	88	\| "_EXE_",
	89	\| "trace2",
	90	\| "004child",
	91	\| "test-tool",
	92	\| "trace2",
	93	\| "004child",
	94	\| "test-tool",
	95	\| "trace2",
	96	\| "001return",
	97	\| "0"
	98	\| ],
	99	\| "child":{
	100	\| "0":{
	101	\| "child_argv":[
	102	\| "_EXE_",
	103	\| "trace2",
	104	\| "004child",
	105	\| "test-tool",
	106	\| "trace2",
	107	\| "001return",
	108	\| "0"
	109	\| ],
	110	\| "child_class":"?",
	111	\| "child_code":0,
	112	\| "use_shell":0
	113	\| }
	114	\| },
	115	\| "exit_code":0,
	116	\| "hierarchy":"trace2",
	117	\| "name":"trace2",
	118	\| "version":"$V"
	119	\| },
	120	\| "_SID0_/_SID1_":{
	121	\| "argv":[
	122	\| "_EXE_",
	123	\| "trace2",
	124	\| "004child",
	125	\| "test-tool",
	126	\| "trace2",
	127	\| "001return",
	128	\| "0"
	129	\| ],
	130	\| "child":{
	131	\| "0":{
	132	\| "child_argv":[
	133	\| "_EXE_",
	134	\| "trace2",
	135	\| "001return",
	136	\| "0"
	137	\| ],
	138	\| "child_class":"?",
	139	\| "child_code":0,
	140	\| "use_shell":0
	141	\| }
	142	\| },
	143	\| "exit_code":0,
	144	\| "hierarchy":"trace2/trace2",
	145	\| "name":"trace2",
	146	\| "version":"$V"
147	\| },
148	\| "_SID0_/_SID1_/_SID2_":{
149	\| "argv":[
150	\| "_EXE_",
151	\| "trace2",
152	\| "001return",
153	\| "0"
154	\| ],
155	\| "exit_code":0,
156	\| "hierarchy":"trace2/trace2/trace2",
157	\| "name":"trace2",
158	\| "version":"$V"
159	\| }
160	\|};
161	EOF
162	test_cmp expect actual
163	'
164
165	# Test listing of all "interesting" config settings.
166
167	test_expect_success JSON_PP 'event stream, list config' '
168	test_when_finished "rm trace.event actual expect" &&
169	git config --local t0212.abc 1 &&
170	git config --local t0212.def "hello world" &&
e4b75d6a	171	GIT_TRACE2_EVENT="$(pwd)/trace.event" GIT_TRACE2_CONFIG_PARAMS="t0212.*" test-tool trace2 001return 0 &&
a15860dc JH	172	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	173	sed -e "s/^\|//" >expect <<-EOF &&
	174	\|VAR1 = {
	175	\| "_SID0_":{
	176	\| "argv":[
	177	\| "_EXE_",
	178	\| "trace2",
	179	\| "001return",
	180	\| "0"
	181	\| ],
	182	\| "exit_code":0,
	183	\| "hierarchy":"trace2",
	184	\| "name":"trace2",
	185	\| "params":[
	186	\| {
	187	\| "param":"t0212.abc",
	188	\| "value":"1"
	189	\| },
	190	\| {
	191	\| "param":"t0212.def",
	192	\| "value":"hello world"
	193	\| }
	194	\| ],
	195	\| "version":"$V"
	196	\| }
	197	\|};
	198	EOF
	199	test_cmp expect actual
	200	'
	201
3d3adaad JS	202	# Test listing of all "interesting" environment variables.
	203
	204	test_expect_success JSON_PP 'event stream, list env vars' '
	205	test_when_finished "rm trace.event actual expect" &&
	206	GIT_TRACE2_EVENT="$(pwd)/trace.event" \
	207	GIT_TRACE2_ENV_VARS="A_VAR,OTHER_VAR,MISSING" \
	208	A_VAR=1 OTHER_VAR="hello world" test-tool trace2 001return 0 &&
	209	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	210	sed -e "s/^\|//" >expect <<-EOF &&
	211	\|VAR1 = {
	212	\| "_SID0_":{
	213	\| "argv":[
	214	\| "_EXE_",
	215	\| "trace2",
	216	\| "001return",
	217	\| "0"
	218	\| ],
	219	\| "exit_code":0,
	220	\| "hierarchy":"trace2",
	221	\| "name":"trace2",
	222	\| "params":[
	223	\| {
	224	\| "param":"A_VAR",
	225	\| "value":"1"
	226	\| },
	227	\| {
	228	\| "param":"OTHER_VAR",
	229	\| "value":"hello world"
	230	\| }
	231	\| ],
	232	\| "version":"$V"
	233	\| }
	234	\|};
	235	EOF
	236	test_cmp expect actual
	237	'
	238
a15860dc JH	239	test_expect_success JSON_PP 'basic trace2_data' '
a15860dc JH	240	test_when_finished "rm trace.event actual expect" &&
e4b75d6a	241	GIT_TRACE2_EVENT="$(pwd)/trace.event" test-tool trace2 006data test_category k1 v1 test_category k2 v2 &&
a15860dc JH	242	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	243	sed -e "s/^\|//" >expect <<-EOF &&
	244	\|VAR1 = {
	245	\| "_SID0_":{
	246	\| "argv":[
	247	\| "_EXE_",
	248	\| "trace2",
	249	\| "006data",
	250	\| "test_category",
	251	\| "k1",
	252	\| "v1",
	253	\| "test_category",
	254	\| "k2",
	255	\| "v2"
	256	\| ],
	257	\| "data":{
	258	\| "test_category":{
	259	\| "k1":"v1",
	260	\| "k2":"v2"
	261	\| }
	262	\| },
	263	\| "exit_code":0,
	264	\| "hierarchy":"trace2",
	265	\| "name":"trace2",
	266	\| "version":"$V"
	267	\| }
	268	\|};
	269	EOF
	270	test_cmp expect actual
	271	'
	272
bce9db6d JH	273	# Now test without environment variables and get all Trace2 settings
	274	# from the global config.
	275
	276	test_expect_success JSON_PP 'using global config, event stream, error event' '
	277	test_when_finished "rm trace.event actual expect" &&
	278	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
	279	test-tool trace2 003error "hello world" "this is a test" &&
	280	perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
	281	sed -e "s/^\|//" >expect <<-EOF &&
	282	\|VAR1 = {
	283	\| "_SID0_":{
	284	\| "argv":[
	285	\| "_EXE_",
	286	\| "trace2",
	287	\| "003error",
	288	\| "hello world",
	289	\| "this is a test"
	290	\| ],
	291	\| "errors":[
	292	\| "%s",
	293	\| "%s"
	294	\| ],
	295	\| "exit_code":0,
	296	\| "hierarchy":"trace2",
	297	\| "name":"trace2",
	298	\| "version":"$V"
	299	\| }
	300	\|};
	301	EOF
	302	test_cmp expect actual
	303	'
	304
83e57b04 JS	305	test_expect_success 'discard traces when there are too many files' '
	306	mkdir trace_target_dir &&
	307	test_when_finished "rm -r trace_target_dir" &&
	308	(
	309	GIT_TRACE2_MAX_FILES=5 &&
	310	export GIT_TRACE2_MAX_FILES &&
	311	cd trace_target_dir &&
	312	test_seq $GIT_TRACE2_MAX_FILES >../expected_filenames.txt &&
	313	xargs touch <../expected_filenames.txt &&
	314	cd .. &&
	315	GIT_TRACE2_EVENT="$(pwd)/trace_target_dir" test-tool trace2 001return 0
	316	) &&
	317	echo git-trace2-discard >>expected_filenames.txt &&
	318	ls trace_target_dir >ls_output.txt &&
87db61a4 JS	319	test_cmp expected_filenames.txt ls_output.txt &&
	320	head -n1 trace_target_dir/git-trace2-discard \| grep \"event\":\"version\" &&
	321	head -n2 trace_target_dir/git-trace2-discard \| tail -n1 \| grep \"event\":\"too_many_files\"
83e57b04 JS	322	'
83e57b04 JS	323
a15860dc	324	test_done