Raw
1 #!/bin/sh
2
3 test_description='test trace2 facility (normal target)'
4
5 . ./test-lib.sh
6
7 # Turn off any inherited trace2 settings for this test.
8 sane_unset GIT_TRACE2 GIT_TRACE2_PERF GIT_TRACE2_EVENT
9 sane_unset GIT_TRACE2_BRIEF
10 sane_unset GIT_TRACE2_CONFIG_PARAMS
11
12 # Add t/helper directory to PATH so that we can use a relative
13 # path to run nested instances of test-tool.exe (see 004child).
14 # This helps with HEREDOC comparisons later.
15 TTDIR="$GIT_BUILD_DIR/t/helper/" && export TTDIR
16 PATH="$TTDIR:$PATH" && export PATH
17
18 # Warning: use of 'test_cmp' may run test-tool.exe and/or git.exe
19 # Warning: to do the actual diff/comparison, so the HEREDOCs here
20 # Warning: only cover our actual calls to test-tool and/or git.
21 # Warning: So you may see extra lines in artifact files when
22 # Warning: interactively debugging.
23
24 V=$(git version | sed -e 's/^git version //') && export V
25
26 # There are multiple trace2 targets: normal, perf, and event.
27 # Trace2 events will/can be written to each active target (subject
28 # to whatever filtering that target decides to do).
29 # This script tests the normal target in isolation.
30 #
31 # Defer setting GIT_TRACE2 until the actual command line we want to test
32 # because hidden git and test-tool commands run by the test harness
33 # can contaminate our output.
34
35 # Enable "brief" feature which turns off "<clock> <file>:<line> " prefix.
36 GIT_TRACE2_BRIEF=1 && export GIT_TRACE2_BRIEF
37
38 # Basic tests of the trace2 normal stream. Since this stream is used
39 # primarily with printf-style debugging/tracing, we do limited testing
40 # here.
41 #
42 # We do confirm the following API features:
43 # [] the 'version <v>' event
44 # [] the 'start <argv>' event
45 # [] the 'cmd_name <name>' event
46 # [] the 'exit <time> code:<code>' event
47 # [] the 'atexit <time> code:<code>' event
48 #
49 # Fields of the form _FIELD_ are tokens that have been replaced (such
50 # as the elapsed time).
51
52 # Verb 001return
53 #
54 # Implicit return from cmd_<verb> function propagates <code>.
55
56 scrub_normal () {
57 # Scrub the variable fields from the normal trace2 output to make
58 # testing easier:
59 #
60 # 1. Various messages include an elapsed time in the middle of the
61 # message. Replace the time with a placeholder to simplify our
62 # HEREDOC in the test script.
63 #
64 # 2. We expect:
65 #
66 # start <argv0> [<argv1> [<argv2> [...]]]
67 #
68 # where argv0 might be a relative or absolute path, with or
69 # without quotes, and platform dependent. Replace argv0 with a
70 # token for HEREDOC matching in the test script.
71 #
72 # 3. Likewise, the 'cmd_path' message breaks out argv[0].
73 #
74 # This line is only emitted when RUNTIME_PREFIX is defined,
75 # so just omit it for testing purposes.
76 #
77 # 4. 'cmd_ancestry' output depends on how the test is run and
78 # is not relevant to the features we are testing here.
79 # Ancestry tests are covered in t0213-trace2-ancestry.sh instead.
80 sed \
81 -e 's/elapsed:[0-9]*\.[0-9][0-9]*\([eE][-+]\{0,1\}[0-9][0-9]*\)\{0,1\}/elapsed:_TIME_/g' \
82 -e "s/^start '[^']*' \(.*\)/start _EXE_ \1/" \
83 -e 's/^start [^ ][^ ]* \(.*\)/start _EXE_ \1/' \
84 -e '/^cmd_path/d' \
85 -e '/^cmd_ancestry/d'
86 }
87
88 test_expect_success 'normal stream, return code 0' '
89 test_when_finished "rm trace.normal actual expect" &&
90 GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 001return 0 &&
91 scrub_normal <trace.normal >actual &&
92 cat >expect <<-EOF &&
93 version $V
94 start _EXE_ trace2 001return 0
95 cmd_name trace2 (trace2)
96 exit elapsed:_TIME_ code:0
97 atexit elapsed:_TIME_ code:0
98 EOF
99 test_cmp expect actual
100 '
101
102 test_expect_success 'normal stream, return code 1' '
103 test_when_finished "rm trace.normal actual expect" &&
104 test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 001return 1 &&
105 scrub_normal <trace.normal >actual &&
106 cat >expect <<-EOF &&
107 version $V
108 start _EXE_ trace2 001return 1
109 cmd_name trace2 (trace2)
110 exit elapsed:_TIME_ code:1
111 atexit elapsed:_TIME_ code:1
112 EOF
113 test_cmp expect actual
114 '
115
116 test_expect_success 'automatic filename' '
117 test_when_finished "rm -r traces actual expect" &&
118 mkdir traces &&
119 GIT_TRACE2="$(pwd)/traces" test-tool trace2 001return 0 &&
120 scrub_normal <"$(ls traces/*)" >actual &&
121 cat >expect <<-EOF &&
122 version $V
123 start _EXE_ trace2 001return 0
124 cmd_name trace2 (trace2)
125 exit elapsed:_TIME_ code:0
126 atexit elapsed:_TIME_ code:0
127 EOF
128 test_cmp expect actual
129 '
130
131 # Verb 002exit
132 #
133 # Explicit exit(code) from within cmd_<verb> propagates <code>.
134
135 test_expect_success 'normal stream, exit code 0' '
136 test_when_finished "rm trace.normal actual expect" &&
137 GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 002exit 0 &&
138 scrub_normal <trace.normal >actual &&
139 cat >expect <<-EOF &&
140 version $V
141 start _EXE_ trace2 002exit 0
142 cmd_name trace2 (trace2)
143 exit elapsed:_TIME_ code:0
144 atexit elapsed:_TIME_ code:0
145 EOF
146 test_cmp expect actual
147 '
148
149 test_expect_success 'normal stream, exit code 1' '
150 test_when_finished "rm trace.normal actual expect" &&
151 test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 002exit 1 &&
152 scrub_normal <trace.normal >actual &&
153 cat >expect <<-EOF &&
154 version $V
155 start _EXE_ trace2 002exit 1
156 cmd_name trace2 (trace2)
157 exit elapsed:_TIME_ code:1
158 atexit elapsed:_TIME_ code:1
159 EOF
160 test_cmp expect actual
161 '
162
163 # Verb 003error
164 #
165 # To the above, add multiple 'error <msg>' events
166
167 test_expect_success 'normal stream, error event' '
168 test_when_finished "rm trace.normal actual expect" &&
169 GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 003error "hello world" "this is a test" &&
170 scrub_normal <trace.normal >actual &&
171 cat >expect <<-EOF &&
172 version $V
173 start _EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
174 cmd_name trace2 (trace2)
175 error hello world
176 error this is a test
177 exit elapsed:_TIME_ code:0
178 atexit elapsed:_TIME_ code:0
179 EOF
180 test_cmp expect actual
181 '
182
183 # Verb 007bug
184 #
185 # Check that BUG writes to trace2
186
187 test_expect_success 'BUG messages are written to trace2' '
188 test_when_finished "rm trace.normal actual expect" &&
189 test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 007bug &&
190 scrub_normal <trace.normal >actual &&
191 cat >expect <<-EOF &&
192 version $V
193 start _EXE_ trace2 007bug
194 cmd_name trace2 (trace2)
195 error the bug message
196 exit elapsed:_TIME_ code:99
197 atexit elapsed:_TIME_ code:99
198 EOF
199 test_cmp expect actual
200 '
201
202 test_expect_success 'bug messages with BUG_if_bug() are written to trace2' '
203 test_when_finished "rm trace.normal actual expect" &&
204 test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
205 test-tool trace2 008bug 2>err &&
206 cat >expect <<-\EOF &&
207 a bug message
208 another bug message
209 an explicit BUG_if_bug() following bug() call(s) is nice, but not required
210 EOF
211 sed "s/^.*: //" <err >actual &&
212 test_cmp expect actual &&
213
214 scrub_normal <trace.normal >actual &&
215 cat >expect <<-EOF &&
216 version $V
217 start _EXE_ trace2 008bug
218 cmd_name trace2 (trace2)
219 error a bug message
220 error another bug message
221 error an explicit BUG_if_bug() following bug() call(s) is nice, but not required
222 exit elapsed:_TIME_ code:99
223 atexit elapsed:_TIME_ code:99
224 EOF
225 test_cmp expect actual
226 '
227
228 test_expect_success 'bug messages without explicit BUG_if_bug() are written to trace2' '
229 test_when_finished "rm trace.normal actual expect" &&
230 test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
231 test-tool trace2 009bug_BUG 2>err &&
232 cat >expect <<-\EOF &&
233 a bug message
234 another bug message
235 had bug() call(s) in this process without explicit BUG_if_bug()
236 EOF
237 sed "s/^.*: //" <err >actual &&
238 test_cmp expect actual &&
239
240 scrub_normal <trace.normal >actual &&
241 cat >expect <<-EOF &&
242 version $V
243 start _EXE_ trace2 009bug_BUG
244 cmd_name trace2 (trace2)
245 error a bug message
246 error another bug message
247 error on exit(): had bug() call(s) in this process without explicit BUG_if_bug()
248 exit elapsed:_TIME_ code:99
249 atexit elapsed:_TIME_ code:99
250 EOF
251 test_cmp expect actual
252 '
253
254 test_expect_success 'bug messages followed by BUG() are written to trace2' '
255 test_when_finished "rm trace.normal actual expect" &&
256 test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
257 test-tool trace2 010bug_BUG 2>err &&
258 cat >expect <<-\EOF &&
259 a bug message
260 a BUG message
261 EOF
262 sed "s/^.*: //" <err >actual &&
263 test_cmp expect actual &&
264
265 scrub_normal <trace.normal >actual &&
266 cat >expect <<-EOF &&
267 version $V
268 start _EXE_ trace2 010bug_BUG
269 cmd_name trace2 (trace2)
270 error a bug message
271 error a BUG message
272 exit elapsed:_TIME_ code:99
273 atexit elapsed:_TIME_ code:99
274 EOF
275 test_cmp expect actual
276 '
277
278 test_expect_success 'a valueless true configuration variable is handled' '
279 test_when_finished "rm -f trace2.normal actual expect" &&
280 echo >expect &&
281 GIT_TRACE2="$(pwd)/trace2.normal" \
282 GIT_TRACE2_CONFIG_PARAMS=foo.true \
283 git -c foo.true config foo.true >actual &&
284 test_cmp expect actual
285 '
286
287 sane_unset GIT_TRACE2_BRIEF
288
289 # Now test without environment variables and get all Trace2 settings
290 # from the global config.
291
292 test_expect_success 'using global config, normal stream, return code 0' '
293 test_when_finished "rm trace.normal actual expect" &&
294 test_config_global trace2.normalBrief 1 &&
295 test_config_global trace2.normalTarget "$(pwd)/trace.normal" &&
296 test-tool trace2 001return 0 &&
297 scrub_normal <trace.normal >actual &&
298 cat >expect <<-EOF &&
299 version $V
300 start _EXE_ trace2 001return 0
301 cmd_name trace2 (trace2)
302 exit elapsed:_TIME_ code:0
303 atexit elapsed:_TIME_ code:0
304 EOF
305 test_cmp expect actual
306 '
307
308 test_expect_success 'using global config with include' '
309 test_when_finished "rm trace.normal actual expect real.gitconfig" &&
310 test_config_global trace2.normalBrief 1 &&
311 test_config_global trace2.normalTarget "$(pwd)/trace.normal" &&
312 mv "$(pwd)/.gitconfig" "$(pwd)/real.gitconfig" &&
313 test_config_global include.path "$(pwd)/real.gitconfig" &&
314 test-tool trace2 001return 0 &&
315 scrub_normal <trace.normal >actual &&
316 cat >expect <<-EOF &&
317 version $V
318 start _EXE_ trace2 001return 0
319 cmd_name trace2 (trace2)
320 exit elapsed:_TIME_ code:0
321 atexit elapsed:_TIME_ code:0
322 EOF
323 test_cmp expect actual
324 '
325
326 test_expect_success 'unsafe URLs are redacted by default' '
327 test_when_finished \
328 "rm -r trace.normal unredacted.normal clone clone2" &&
329
330 test_config_global \
331 "url.$(pwd).insteadOf" https://user:pwd@example.com/ &&
332 test_config_global trace2.configParams "core.*,remote.*.url" &&
333
334 GIT_TRACE2="$(pwd)/trace.normal" \
335 git clone https://user:pwd@example.com/ clone &&
336 test_grep ! user:pwd trace.normal &&
337
338 GIT_TRACE2_REDACT=0 GIT_TRACE2="$(pwd)/unredacted.normal" \
339 git clone https://user:pwd@example.com/ clone2 &&
340 test_grep "start .* clone https://user:pwd@example.com" unredacted.normal &&
341 test_grep "remote.origin.url=https://user:pwd@example.com" unredacted.normal
342 '
343
344 test_done