diff options
Diffstat (limited to 't/t0211-trace2-perf.sh')
| -rwxr-xr-x | t/t0211-trace2-perf.sh | 347 |
1 files changed, 346 insertions, 1 deletions
diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh index 22d0845..13ef69b 100755 --- a/t/t0211-trace2-perf.sh +++ b/t/t0211-trace2-perf.sh @@ -2,7 +2,7 @@ test_description='test trace2 facility (perf target)' -TEST_PASSES_SANITIZE_LEAK=true +TEST_PASSES_SANITIZE_LEAK=false . ./test-lib.sh # Turn off any inherited trace2 settings for this test. @@ -173,4 +173,349 @@ test_expect_success 'using global config, perf stream, return code 0' ' test_cmp expect actual ' +# Exercise the stopwatch timers in a loop and confirm that we have +# as many start/stop intervals as expected. We cannot really test the +# actual (total, min, max) timer values, so we have to assume that they +# are good, but we can verify the interval count. +# +# The timer "test/test1" should only emit a global summary "timer" event. +# The timer "test/test2" should emit per-thread "th_timer" events and a +# global summary "timer" event. + +have_timer_event () { + thread=$1 event=$2 category=$3 name=$4 intervals=$5 file=$6 && + + pattern="d0|${thread}|${event}||||${category}|name:${name} intervals:${intervals}" && + + grep "${pattern}" ${file} +} + +test_expect_success 'stopwatch timer test/test1' ' + test_when_finished "rm trace.perf actual" && + test_config_global trace2.perfBrief 1 && + test_config_global trace2.perfTarget "$(pwd)/trace.perf" && + + # Use the timer "test1" 5 times from "main". + test-tool trace2 100timer 5 10 && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && + + have_timer_event "main" "timer" "test" "test1" 5 actual +' + +test_expect_success PTHREADS 'stopwatch timer test/test2' ' + test_when_finished "rm trace.perf actual" && + test_config_global trace2.perfBrief 1 && + test_config_global trace2.perfTarget "$(pwd)/trace.perf" && + + # Use the timer "test2" 5 times each in 3 threads. + test-tool trace2 101timer 5 10 3 && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && + + # So we should have 3 per-thread events of 5 each. + have_timer_event "th01:ut_101" "th_timer" "test" "test2" 5 actual && + have_timer_event "th02:ut_101" "th_timer" "test" "test2" 5 actual && + have_timer_event "th03:ut_101" "th_timer" "test" "test2" 5 actual && + + # And we should have 15 total uses. + have_timer_event "main" "timer" "test" "test2" 15 actual +' + +# Exercise the global counters and confirm that we get the expected values. +# +# The counter "test/test1" should only emit a global summary "counter" event. +# The counter "test/test2" could emit per-thread "th_counter" events and a +# global summary "counter" event. + +have_counter_event () { + thread=$1 event=$2 category=$3 name=$4 value=$5 file=$6 && + + pattern="d0|${thread}|${event}||||${category}|name:${name} value:${value}" && + + grep "${patern}" ${file} +} + +test_expect_success 'global counter test/test1' ' + test_when_finished "rm trace.perf actual" && + test_config_global trace2.perfBrief 1 && + test_config_global trace2.perfTarget "$(pwd)/trace.perf" && + + # Use the counter "test1" and add n integers. + test-tool trace2 200counter 1 2 3 4 5 && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && + + have_counter_event "main" "counter" "test" "test1" 15 actual +' + +test_expect_success PTHREADS 'global counter test/test2' ' + test_when_finished "rm trace.perf actual" && + test_config_global trace2.perfBrief 1 && + test_config_global trace2.perfTarget "$(pwd)/trace.perf" && + + # Add 2 integers to the counter "test2" in each of 3 threads. + test-tool trace2 201counter 7 13 3 && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && + + # So we should have 3 per-thread events of 5 each. + have_counter_event "th01:ut_201" "th_counter" "test" "test2" 20 actual && + have_counter_event "th02:ut_201" "th_counter" "test" "test2" 20 actual && + have_counter_event "th03:ut_201" "th_counter" "test" "test2" 20 actual && + + # And we should have a single event with the total across all threads. + have_counter_event "main" "counter" "test" "test2" 60 actual +' + +test_expect_success 'unsafe URLs are redacted by default' ' + test_when_finished \ + "rm -r actual trace.perf unredacted.perf clone clone2" && + + test_config_global \ + "url.$(pwd).insteadOf" https://user:pwd@example.com/ && + test_config_global trace2.configParams "core.*,remote.*.url" && + + GIT_TRACE2_PERF="$(pwd)/trace.perf" \ + git clone https://user:pwd@example.com/ clone && + ! grep user:pwd trace.perf && + + GIT_TRACE2_REDACT=0 GIT_TRACE2_PERF="$(pwd)/unredacted.perf" \ + git clone https://user:pwd@example.com/ clone2 && + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <unredacted.perf >actual && + grep "d0|main|start|.* clone https://user:pwd@example.com" actual && + grep "d0|main|def_param|.*|remote.origin.url:https://user:pwd@example.com" actual +' + +# Confirm that the requested command produces a "cmd_name" and a +# set of "def_param" events. +# +try_simple () { + test_when_finished "rm prop.perf actual" && + + cmd=$1 && + cmd_name=$2 && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + $cmd && + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + grep "d0|main|cmd_name|.*|$cmd_name" actual && + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual +} + +# Representative mainstream builtin Git command dispatched +# in run_builtin() in git.c +# +test_expect_success 'expect def_params for normal builtin command' ' + try_simple "git version" "version" +' + +# Representative query command dispatched in handle_options() +# in git.c +# +test_expect_success 'expect def_params for query command' ' + try_simple "git --man-path" "_query_" +' + +# remote-curl.c does not use the builtin setup in git.c, so confirm +# that executables built from remote-curl.c emit def_params. +# +# Also tests the dashed-command handling where "git foo" silently +# spawns "git-foo". Make sure that both commands should emit +# def_params. +# +# Pass bogus arguments to remote-https and allow the command to fail +# because we don't actually have a remote to fetch from. We just want +# to see the run-dashed code run an executable built from +# remote-curl.c rather than git.c. Confirm that we get def_param +# events from both layers. +# +test_expect_success 'expect def_params for remote-curl and _run_dashed_' ' + test_when_finished "rm prop.perf actual" && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + test_might_fail env \ + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + git remote-http x y && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + + grep "d0|main|cmd_name|.*|_run_dashed_" actual && + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual && + + grep "d1|main|cmd_name|.*|remote-curl" actual && + grep "d1|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d1|main|def_param|.*|ENV_PROP_FOO:blue" actual +' + +# Similarly, `git-http-fetch` is not built from git.c so do a +# trivial fetch so that the main git.c run-dashed code spawns +# an executable built from http-fetch.c. Confirm that we get +# def_param events from both layers. +# +test_expect_success 'expect def_params for http-fetch and _run_dashed_' ' + test_when_finished "rm prop.perf actual" && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + test_might_fail env \ + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + git http-fetch --stdin file:/// <<-EOF && + EOF + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + + grep "d0|main|cmd_name|.*|_run_dashed_" actual && + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual && + + grep "d1|main|cmd_name|.*|http-fetch" actual && + grep "d1|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d1|main|def_param|.*|ENV_PROP_FOO:blue" actual +' + +# Historically, alias expansion explicitly emitted the def_param +# events (independent of whether the command was a builtin, a Git +# command or arbitrary shell command) so that it wasn't dependent +# upon the unpeeling of the alias. Let's make sure that we preserve +# the net effect. +# +test_expect_success 'expect def_params during git alias expansion' ' + test_when_finished "rm prop.perf actual" && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + test_config_global "alias.xxx" "version" && + + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + git xxx && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + + # "git xxx" is first mapped to "git-xxx" and the child will fail. + grep "d0|main|cmd_name|.*|_run_dashed_ (_run_dashed_)" actual && + + # We unpeel that and substitute "version" into "xxx" (giving + # "git version") and update the cmd_name event. + grep "d0|main|cmd_name|.*|_run_git_alias_ (_run_dashed_/_run_git_alias_)" actual && + + # These def_param events could be associated with either of the + # above cmd_name events. It does not matter. + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual && + + # The "git version" child sees a different cmd_name hierarchy. + # Also test the def_param (only for completeness). + grep "d1|main|cmd_name|.*|version (_run_dashed_/_run_git_alias_/version)" actual && + grep "d1|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d1|main|def_param|.*|ENV_PROP_FOO:blue" actual +' + +test_expect_success 'expect def_params during shell alias expansion' ' + test_when_finished "rm prop.perf actual" && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + test_config_global "alias.xxx" "!git version" && + + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + git xxx && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + + # "git xxx" is first mapped to "git-xxx" and the child will fail. + grep "d0|main|cmd_name|.*|_run_dashed_ (_run_dashed_)" actual && + + # We unpeel that and substitute "git version" for "git xxx" (as a + # shell command. Another cmd_name event is emitted as we unpeel. + grep "d0|main|cmd_name|.*|_run_shell_alias_ (_run_dashed_/_run_shell_alias_)" actual && + + # These def_param events could be associated with either of the + # above cmd_name events. It does not matter. + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual && + + # We get the following only because we used a git command for the + # shell command. In general, it could have been a shell script and + # we would see nothing. + # + # The child knows the cmd_name hierarchy so it includes it. + grep "d1|main|cmd_name|.*|version (_run_dashed_/_run_shell_alias_/version)" actual && + grep "d1|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d1|main|def_param|.*|ENV_PROP_FOO:blue" actual +' + +test_expect_success 'expect def_params during nested git alias expansion' ' + test_when_finished "rm prop.perf actual" && + + test_config_global "trace2.configParams" "cfg.prop.*" && + test_config_global "trace2.envvars" "ENV_PROP_FOO,ENV_PROP_BAR" && + + test_config_global "cfg.prop.foo" "red" && + + test_config_global "alias.xxx" "yyy" && + test_config_global "alias.yyy" "version" && + + ENV_PROP_FOO=blue \ + GIT_TRACE2_PERF="$(pwd)/prop.perf" \ + git xxx && + + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <prop.perf >actual && + + # "git xxx" is first mapped to "git-xxx" and try to spawn "git-xxx" + # and the child will fail. + grep "d0|main|cmd_name|.*|_run_dashed_ (_run_dashed_)" actual && + grep "d0|main|child_start|.*|.* class:dashed argv:\[git-xxx\]" actual && + + # We unpeel that and substitute "yyy" into "xxx" (giving "git yyy") + # and spawn "git-yyy" and the child will fail. + grep "d0|main|alias|.*|alias:xxx argv:\[yyy\]" actual && + grep "d0|main|cmd_name|.*|_run_dashed_ (_run_dashed_/_run_dashed_)" actual && + grep "d0|main|child_start|.*|.* class:dashed argv:\[git-yyy\]" actual && + + # We unpeel that and substitute "version" into "xxx" (giving + # "git version") and update the cmd_name event. + grep "d0|main|alias|.*|alias:yyy argv:\[version\]" actual && + grep "d0|main|cmd_name|.*|_run_git_alias_ (_run_dashed_/_run_dashed_/_run_git_alias_)" actual && + + # These def_param events could be associated with any of the + # above cmd_name events. It does not matter. + grep "d0|main|def_param|.*|cfg.prop.foo:red" actual >actual.matches && + grep "d0|main|def_param|.*|ENV_PROP_FOO:blue" actual && + + # However, we do not want them repeated each time we unpeel. + test_line_count = 1 actual.matches && + + # The "git version" child sees a different cmd_name hierarchy. + # Also test the def_param (only for completeness). + grep "d1|main|cmd_name|.*|version (_run_dashed_/_run_dashed_/_run_git_alias_/version)" actual && + grep "d1|main|def_param|.*|cfg.prop.foo:red" actual && + grep "d1|main|def_param|.*|ENV_PROP_FOO:blue" actual +' + test_done |