]>
Commit | Line | Data |
---|---|---|
a15860dc JH |
1 | #!/bin/sh |
2 | ||
3 | test_description='test trace2 facility (perf target)' | |
0033ab3f | 4 | |
c73e7f80 | 5 | TEST_PASSES_SANITIZE_LEAK=false |
a15860dc JH |
6 | . ./test-lib.sh |
7 | ||
bce9db6d | 8 | # Turn off any inherited trace2 settings for this test. |
e4b75d6a SG |
9 | sane_unset GIT_TRACE2 GIT_TRACE2_PERF GIT_TRACE2_EVENT |
10 | sane_unset GIT_TRACE2_PERF_BRIEF | |
11 | sane_unset GIT_TRACE2_CONFIG_PARAMS | |
bce9db6d | 12 | |
a15860dc JH |
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 | # Enable "brief" feature which turns off the prefix: | |
37 | # "<clock> <file>:<line> | <nr_parents> | " | |
e4b75d6a | 38 | GIT_TRACE2_PERF_BRIEF=1 && export GIT_TRACE2_PERF_BRIEF |
a15860dc JH |
39 | |
40 | # Repeat some of the t0210 tests using the perf target stream instead of | |
41 | # the normal stream. | |
42 | # | |
43 | # Tokens here of the form _FIELD_ have been replaced in the observed output. | |
44 | ||
45 | # Verb 001return | |
46 | # | |
47 | # Implicit return from cmd_<verb> function propagates <code>. | |
48 | ||
49 | test_expect_success 'perf stream, return code 0' ' | |
50 | test_when_finished "rm trace.perf actual expect" && | |
e4b75d6a | 51 | GIT_TRACE2_PERF="$(pwd)/trace.perf" test-tool trace2 001return 0 && |
a15860dc JH |
52 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && |
53 | cat >expect <<-EOF && | |
54 | d0|main|version|||||$V | |
39f43177 | 55 | d0|main|start||_T_ABS_|||_EXE_ trace2 001return 0 |
a15860dc JH |
56 | d0|main|cmd_name|||||trace2 (trace2) |
57 | d0|main|exit||_T_ABS_|||code:0 | |
58 | d0|main|atexit||_T_ABS_|||code:0 | |
59 | EOF | |
60 | test_cmp expect actual | |
61 | ' | |
62 | ||
63 | test_expect_success 'perf stream, return code 1' ' | |
64 | test_when_finished "rm trace.perf actual expect" && | |
e4b75d6a | 65 | test_must_fail env GIT_TRACE2_PERF="$(pwd)/trace.perf" test-tool trace2 001return 1 && |
a15860dc JH |
66 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && |
67 | cat >expect <<-EOF && | |
68 | d0|main|version|||||$V | |
39f43177 | 69 | d0|main|start||_T_ABS_|||_EXE_ trace2 001return 1 |
a15860dc JH |
70 | d0|main|cmd_name|||||trace2 (trace2) |
71 | d0|main|exit||_T_ABS_|||code:1 | |
72 | d0|main|atexit||_T_ABS_|||code:1 | |
73 | EOF | |
74 | test_cmp expect actual | |
75 | ' | |
76 | ||
77 | # Verb 003error | |
78 | # | |
79 | # To the above, add multiple 'error <msg>' events | |
80 | ||
81 | test_expect_success 'perf stream, error event' ' | |
82 | test_when_finished "rm trace.perf actual expect" && | |
e4b75d6a | 83 | GIT_TRACE2_PERF="$(pwd)/trace.perf" test-tool trace2 003error "hello world" "this is a test" && |
a15860dc JH |
84 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && |
85 | cat >expect <<-EOF && | |
86 | d0|main|version|||||$V | |
39f43177 | 87 | d0|main|start||_T_ABS_|||_EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\'' |
a15860dc JH |
88 | d0|main|cmd_name|||||trace2 (trace2) |
89 | d0|main|error|||||hello world | |
90 | d0|main|error|||||this is a test | |
91 | d0|main|exit||_T_ABS_|||code:0 | |
92 | d0|main|atexit||_T_ABS_|||code:0 | |
93 | EOF | |
94 | test_cmp expect actual | |
95 | ' | |
96 | ||
97 | # Verb 004child | |
98 | # | |
99 | # Test nested spawning of child processes. | |
100 | # | |
101 | # Conceptually, this looks like: | |
102 | # P1: TT trace2 004child | |
103 | # P2: |--- TT trace2 004child | |
104 | # P3: |--- TT trace2 001return 0 | |
105 | # | |
106 | # Which should generate events: | |
107 | # P1: version | |
108 | # P1: start | |
109 | # P1: cmd_name | |
110 | # P1: child_start | |
111 | # P2: version | |
112 | # P2: start | |
113 | # P2: cmd_name | |
114 | # P2: child_start | |
115 | # P3: version | |
116 | # P3: start | |
117 | # P3: cmd_name | |
118 | # P3: exit | |
119 | # P3: atexit | |
120 | # P2: child_exit | |
121 | # P2: exit | |
122 | # P2: atexit | |
123 | # P1: child_exit | |
124 | # P1: exit | |
125 | # P1: atexit | |
126 | ||
127 | test_expect_success 'perf stream, child processes' ' | |
128 | test_when_finished "rm trace.perf actual expect" && | |
e4b75d6a | 129 | GIT_TRACE2_PERF="$(pwd)/trace.perf" test-tool trace2 004child test-tool trace2 004child test-tool trace2 001return 0 && |
a15860dc JH |
130 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && |
131 | cat >expect <<-EOF && | |
132 | d0|main|version|||||$V | |
39f43177 | 133 | d0|main|start||_T_ABS_|||_EXE_ trace2 004child test-tool trace2 004child test-tool trace2 001return 0 |
a15860dc | 134 | d0|main|cmd_name|||||trace2 (trace2) |
742ed633 | 135 | d0|main|child_start||_T_ABS_|||[ch0] class:? argv:[test-tool trace2 004child test-tool trace2 001return 0] |
a15860dc | 136 | d1|main|version|||||$V |
39f43177 | 137 | d1|main|start||_T_ABS_|||_EXE_ trace2 004child test-tool trace2 001return 0 |
a15860dc | 138 | d1|main|cmd_name|||||trace2 (trace2/trace2) |
742ed633 | 139 | d1|main|child_start||_T_ABS_|||[ch0] class:? argv:[test-tool trace2 001return 0] |
a15860dc | 140 | d2|main|version|||||$V |
39f43177 | 141 | d2|main|start||_T_ABS_|||_EXE_ trace2 001return 0 |
a15860dc JH |
142 | d2|main|cmd_name|||||trace2 (trace2/trace2/trace2) |
143 | d2|main|exit||_T_ABS_|||code:0 | |
144 | d2|main|atexit||_T_ABS_|||code:0 | |
145 | d1|main|child_exit||_T_ABS_|_T_REL_||[ch0] pid:_PID_ code:0 | |
146 | d1|main|exit||_T_ABS_|||code:0 | |
147 | d1|main|atexit||_T_ABS_|||code:0 | |
148 | d0|main|child_exit||_T_ABS_|_T_REL_||[ch0] pid:_PID_ code:0 | |
149 | d0|main|exit||_T_ABS_|||code:0 | |
150 | d0|main|atexit||_T_ABS_|||code:0 | |
151 | EOF | |
152 | test_cmp expect actual | |
153 | ' | |
154 | ||
e4b75d6a | 155 | sane_unset GIT_TRACE2_PERF_BRIEF |
bce9db6d JH |
156 | |
157 | # Now test without environment variables and get all Trace2 settings | |
158 | # from the global config. | |
159 | ||
160 | test_expect_success 'using global config, perf stream, return code 0' ' | |
161 | test_when_finished "rm trace.perf actual expect" && | |
162 | test_config_global trace2.perfBrief 1 && | |
163 | test_config_global trace2.perfTarget "$(pwd)/trace.perf" && | |
164 | test-tool trace2 001return 0 && | |
165 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && | |
166 | cat >expect <<-EOF && | |
167 | d0|main|version|||||$V | |
168 | d0|main|start||_T_ABS_|||_EXE_ trace2 001return 0 | |
169 | d0|main|cmd_name|||||trace2 (trace2) | |
170 | d0|main|exit||_T_ABS_|||code:0 | |
171 | d0|main|atexit||_T_ABS_|||code:0 | |
172 | EOF | |
173 | test_cmp expect actual | |
174 | ' | |
175 | ||
8ad57564 JH |
176 | # Exercise the stopwatch timers in a loop and confirm that we have |
177 | # as many start/stop intervals as expected. We cannot really test the | |
178 | # actual (total, min, max) timer values, so we have to assume that they | |
179 | # are good, but we can verify the interval count. | |
180 | # | |
181 | # The timer "test/test1" should only emit a global summary "timer" event. | |
182 | # The timer "test/test2" should emit per-thread "th_timer" events and a | |
183 | # global summary "timer" event. | |
184 | ||
185 | have_timer_event () { | |
186 | thread=$1 event=$2 category=$3 name=$4 intervals=$5 file=$6 && | |
187 | ||
188 | pattern="d0|${thread}|${event}||||${category}|name:${name} intervals:${intervals}" && | |
189 | ||
190 | grep "${pattern}" ${file} | |
191 | } | |
192 | ||
193 | test_expect_success 'stopwatch timer test/test1' ' | |
194 | test_when_finished "rm trace.perf actual" && | |
195 | test_config_global trace2.perfBrief 1 && | |
196 | test_config_global trace2.perfTarget "$(pwd)/trace.perf" && | |
197 | ||
198 | # Use the timer "test1" 5 times from "main". | |
199 | test-tool trace2 100timer 5 10 && | |
200 | ||
201 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && | |
202 | ||
203 | have_timer_event "main" "timer" "test" "test1" 5 actual | |
204 | ' | |
205 | ||
e48a21df | 206 | test_expect_success PTHREADS 'stopwatch timer test/test2' ' |
8ad57564 JH |
207 | test_when_finished "rm trace.perf actual" && |
208 | test_config_global trace2.perfBrief 1 && | |
209 | test_config_global trace2.perfTarget "$(pwd)/trace.perf" && | |
210 | ||
211 | # Use the timer "test2" 5 times each in 3 threads. | |
212 | test-tool trace2 101timer 5 10 3 && | |
213 | ||
214 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && | |
215 | ||
216 | # So we should have 3 per-thread events of 5 each. | |
217 | have_timer_event "th01:ut_101" "th_timer" "test" "test2" 5 actual && | |
218 | have_timer_event "th02:ut_101" "th_timer" "test" "test2" 5 actual && | |
219 | have_timer_event "th03:ut_101" "th_timer" "test" "test2" 5 actual && | |
220 | ||
221 | # And we should have 15 total uses. | |
222 | have_timer_event "main" "timer" "test" "test2" 15 actual | |
223 | ' | |
224 | ||
81071626 JH |
225 | # Exercise the global counters and confirm that we get the expected values. |
226 | # | |
227 | # The counter "test/test1" should only emit a global summary "counter" event. | |
228 | # The counter "test/test2" could emit per-thread "th_counter" events and a | |
229 | # global summary "counter" event. | |
230 | ||
231 | have_counter_event () { | |
232 | thread=$1 event=$2 category=$3 name=$4 value=$5 file=$6 && | |
233 | ||
234 | pattern="d0|${thread}|${event}||||${category}|name:${name} value:${value}" && | |
235 | ||
236 | grep "${patern}" ${file} | |
237 | } | |
238 | ||
239 | test_expect_success 'global counter test/test1' ' | |
240 | test_when_finished "rm trace.perf actual" && | |
241 | test_config_global trace2.perfBrief 1 && | |
242 | test_config_global trace2.perfTarget "$(pwd)/trace.perf" && | |
243 | ||
244 | # Use the counter "test1" and add n integers. | |
245 | test-tool trace2 200counter 1 2 3 4 5 && | |
246 | ||
247 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && | |
248 | ||
249 | have_counter_event "main" "counter" "test" "test1" 15 actual | |
250 | ' | |
251 | ||
e48a21df | 252 | test_expect_success PTHREADS 'global counter test/test2' ' |
81071626 JH |
253 | test_when_finished "rm trace.perf actual" && |
254 | test_config_global trace2.perfBrief 1 && | |
255 | test_config_global trace2.perfTarget "$(pwd)/trace.perf" && | |
256 | ||
257 | # Add 2 integers to the counter "test2" in each of 3 threads. | |
258 | test-tool trace2 201counter 7 13 3 && | |
259 | ||
260 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && | |
261 | ||
262 | # So we should have 3 per-thread events of 5 each. | |
263 | have_counter_event "th01:ut_201" "th_counter" "test" "test2" 20 actual && | |
264 | have_counter_event "th02:ut_201" "th_counter" "test" "test2" 20 actual && | |
265 | have_counter_event "th03:ut_201" "th_counter" "test" "test2" 20 actual && | |
266 | ||
267 | # And we should have a single event with the total across all threads. | |
268 | have_counter_event "main" "counter" "test" "test2" 60 actual | |
269 | ' | |
270 | ||
c73e7f80 JH |
271 | test_expect_success 'unsafe URLs are redacted by default' ' |
272 | test_when_finished \ | |
273 | "rm -r actual trace.perf unredacted.perf clone clone2" && | |
274 | ||
275 | test_config_global \ | |
276 | "url.$(pwd).insteadOf" https://user:pwd@example.com/ && | |
277 | test_config_global trace2.configParams "core.*,remote.*.url" && | |
278 | ||
279 | GIT_TRACE2_PERF="$(pwd)/trace.perf" \ | |
280 | git clone https://user:pwd@example.com/ clone && | |
281 | ! grep user:pwd trace.perf && | |
282 | ||
283 | GIT_TRACE2_REDACT=0 GIT_TRACE2_PERF="$(pwd)/unredacted.perf" \ | |
284 | git clone https://user:pwd@example.com/ clone2 && | |
285 | perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <unredacted.perf >actual && | |
286 | grep "d0|main|start|.* clone https://user:pwd@example.com" actual && | |
287 | grep "d0|main|def_param|.*|remote.origin.url:https://user:pwd@example.com" actual | |
288 | ' | |
289 | ||
a15860dc | 290 | test_done |