t/t0210-trace2-normal.sh

   1 #!/bin/sh
   2
   3 test_description='test trace2 facility (normal target)'
   4
   5 TEST_PASSES_SANITIZE_LEAK=false
   6 . ./test-lib.sh
   7
   8 # Turn off any inherited trace2 settings for this test.
   9 sane_unset GIT_TRACE2 GIT_TRACE2_PERF GIT_TRACE2_EVENT
  10 sane_unset GIT_TRACE2_BRIEF
  11 sane_unset GIT_TRACE2_CONFIG_PARAMS
  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
  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 # This script tests the normal target in isolation.
  31 #
  32 # Defer setting GIT_TRACE2 until the actual command line we want to test
  33 # because hidden git and test-tool commands run by the test harness
  34 # can contaminate our output.
  35
  36 # Enable "brief" feature which turns off "<clock> <file>:<line> " prefix.
  37 GIT_TRACE2_BRIEF=1 && export GIT_TRACE2_BRIEF
  38
  39 # Basic tests of the trace2 normal stream.  Since this stream is used
  40 # primarily with printf-style debugging/tracing, we do limited testing
  41 # here.
  42 #
  43 # We do confirm the following API features:
  44 # [] the 'version <v>' event
  45 # [] the 'start <argv>' event
  46 # [] the 'cmd_name <name>' event
  47 # [] the 'exit <time> code:<code>' event
  48 # [] the 'atexit <time> code:<code>' event
  49 #
  50 # Fields of the form _FIELD_ are tokens that have been replaced (such
  51 # as the elapsed time).
  52
  53 # Verb 001return
  54 #
  55 # Implicit return from cmd_<verb> function propagates <code>.
  56
  57 test_expect_success 'normal stream, return code 0' '
  58         test_when_finished "rm trace.normal actual expect" &&
  59         GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 001return 0 &&
  60         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
  61         cat >expect <<-EOF &&
  62                 version $V
  63                 start _EXE_ trace2 001return 0
  64                 cmd_name trace2 (trace2)
  65                 exit elapsed:_TIME_ code:0
  66                 atexit elapsed:_TIME_ code:0
  67         EOF
  68         test_cmp expect actual
  69 '
  70
  71 test_expect_success 'normal stream, return code 1' '
  72         test_when_finished "rm trace.normal actual expect" &&
  73         test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 001return 1 &&
  74         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
  75         cat >expect <<-EOF &&
  76                 version $V
  77                 start _EXE_ trace2 001return 1
  78                 cmd_name trace2 (trace2)
  79                 exit elapsed:_TIME_ code:1
  80                 atexit elapsed:_TIME_ code:1
  81         EOF
  82         test_cmp expect actual
  83 '
  84
  85 test_expect_success 'automatic filename' '
  86         test_when_finished "rm -r traces actual expect" &&
  87         mkdir traces &&
  88         GIT_TRACE2="$(pwd)/traces" test-tool trace2 001return 0 &&
  89         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <"$(ls traces/*)" >actual &&
  90         cat >expect <<-EOF &&
  91                 version $V
  92                 start _EXE_ trace2 001return 0
  93                 cmd_name trace2 (trace2)
  94                 exit elapsed:_TIME_ code:0
  95                 atexit elapsed:_TIME_ code:0
  96         EOF
  97         test_cmp expect actual
  98 '
  99
 100 # Verb 002exit
 101 #
 102 # Explicit exit(code) from within cmd_<verb> propagates <code>.
 103
 104 test_expect_success 'normal stream, exit code 0' '
 105         test_when_finished "rm trace.normal actual expect" &&
 106         GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 002exit 0 &&
 107         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 108         cat >expect <<-EOF &&
 109                 version $V
 110                 start _EXE_ trace2 002exit 0
 111                 cmd_name trace2 (trace2)
 112                 exit elapsed:_TIME_ code:0
 113                 atexit elapsed:_TIME_ code:0
 114         EOF
 115         test_cmp expect actual
 116 '
 117
 118 test_expect_success 'normal stream, exit code 1' '
 119         test_when_finished "rm trace.normal actual expect" &&
 120         test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 002exit 1 &&
 121         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 122         cat >expect <<-EOF &&
 123                 version $V
 124                 start _EXE_ trace2 002exit 1
 125                 cmd_name trace2 (trace2)
 126                 exit elapsed:_TIME_ code:1
 127                 atexit elapsed:_TIME_ code:1
 128         EOF
 129         test_cmp expect actual
 130 '
 131
 132 # Verb 003error
 133 #
 134 # To the above, add multiple 'error <msg>' events
 135
 136 test_expect_success 'normal stream, error event' '
 137         test_when_finished "rm trace.normal actual expect" &&
 138         GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 003error "hello world" "this is a test" &&
 139         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 140         cat >expect <<-EOF &&
 141                 version $V
 142                 start _EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\''
 143                 cmd_name trace2 (trace2)
 144                 error hello world
 145                 error this is a test
 146                 exit elapsed:_TIME_ code:0
 147                 atexit elapsed:_TIME_ code:0
 148         EOF
 149         test_cmp expect actual
 150 '
 151
 152 # Verb 007bug
 153 #
 154 # Check that BUG writes to trace2
 155
 156 test_expect_success 'BUG messages are written to trace2' '
 157         test_when_finished "rm trace.normal actual expect" &&
 158         test_must_fail env GIT_TRACE2="$(pwd)/trace.normal" test-tool trace2 007bug &&
 159         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 160         cat >expect <<-EOF &&
 161                 version $V
 162                 start _EXE_ trace2 007bug
 163                 cmd_name trace2 (trace2)
 164                 error the bug message
 165                 exit elapsed:_TIME_ code:99
 166                 atexit elapsed:_TIME_ code:99
 167         EOF
 168         test_cmp expect actual
 169 '
 170
 171 test_expect_success 'bug messages with BUG_if_bug() are written to trace2' '
 172         test_when_finished "rm trace.normal actual expect" &&
 173         test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
 174                 test-tool trace2 008bug 2>err &&
 175         cat >expect <<-\EOF &&
 176         a bug message
 177         another bug message
 178         an explicit BUG_if_bug() following bug() call(s) is nice, but not required
 179         EOF
 180         sed "s/^.*: //" <err >actual &&
 181         test_cmp expect actual &&
 182
 183         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 184         cat >expect <<-EOF &&
 185                 version $V
 186                 start _EXE_ trace2 008bug
 187                 cmd_name trace2 (trace2)
 188                 error a bug message
 189                 error another bug message
 190                 error an explicit BUG_if_bug() following bug() call(s) is nice, but not required
 191                 exit elapsed:_TIME_ code:99
 192                 atexit elapsed:_TIME_ code:99
 193         EOF
 194         test_cmp expect actual
 195 '
 196
 197 test_expect_success 'bug messages without explicit BUG_if_bug() are written to trace2' '
 198         test_when_finished "rm trace.normal actual expect" &&
 199         test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
 200                 test-tool trace2 009bug_BUG 2>err &&
 201         cat >expect <<-\EOF &&
 202         a bug message
 203         another bug message
 204         had bug() call(s) in this process without explicit BUG_if_bug()
 205         EOF
 206         sed "s/^.*: //" <err >actual &&
 207         test_cmp expect actual &&
 208
 209         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 210         cat >expect <<-EOF &&
 211                 version $V
 212                 start _EXE_ trace2 009bug_BUG
 213                 cmd_name trace2 (trace2)
 214                 error a bug message
 215                 error another bug message
 216                 error on exit(): had bug() call(s) in this process without explicit BUG_if_bug()
 217                 exit elapsed:_TIME_ code:99
 218                 atexit elapsed:_TIME_ code:99
 219         EOF
 220         test_cmp expect actual
 221 '
 222
 223 test_expect_success 'bug messages followed by BUG() are written to trace2' '
 224         test_when_finished "rm trace.normal actual expect" &&
 225         test_expect_code 99 env GIT_TRACE2="$(pwd)/trace.normal" \
 226                 test-tool trace2 010bug_BUG 2>err &&
 227         cat >expect <<-\EOF &&
 228         a bug message
 229         a BUG message
 230         EOF
 231         sed "s/^.*: //" <err >actual &&
 232         test_cmp expect actual &&
 233
 234         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 235         cat >expect <<-EOF &&
 236                 version $V
 237                 start _EXE_ trace2 010bug_BUG
 238                 cmd_name trace2 (trace2)
 239                 error a bug message
 240                 error a BUG message
 241                 exit elapsed:_TIME_ code:99
 242                 atexit elapsed:_TIME_ code:99
 243         EOF
 244         test_cmp expect actual
 245 '
 246
 247 sane_unset GIT_TRACE2_BRIEF
 248
 249 # Now test without environment variables and get all Trace2 settings
 250 # from the global config.
 251
 252 test_expect_success 'using global config, normal stream, return code 0' '
 253         test_when_finished "rm trace.normal actual expect" &&
 254         test_config_global trace2.normalBrief 1 &&
 255         test_config_global trace2.normalTarget "$(pwd)/trace.normal" &&
 256         test-tool trace2 001return 0 &&
 257         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 258         cat >expect <<-EOF &&
 259                 version $V
 260                 start _EXE_ trace2 001return 0
 261                 cmd_name trace2 (trace2)
 262                 exit elapsed:_TIME_ code:0
 263                 atexit elapsed:_TIME_ code:0
 264         EOF
 265         test_cmp expect actual
 266 '
 267
 268 test_expect_success 'using global config with include' '
 269         test_when_finished "rm trace.normal actual expect real.gitconfig" &&
 270         test_config_global trace2.normalBrief 1 &&
 271         test_config_global trace2.normalTarget "$(pwd)/trace.normal" &&
 272         mv "$(pwd)/.gitconfig" "$(pwd)/real.gitconfig" &&
 273         test_config_global include.path "$(pwd)/real.gitconfig" &&
 274         test-tool trace2 001return 0 &&
 275         perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual &&
 276         cat >expect <<-EOF &&
 277                 version $V
 278                 start _EXE_ trace2 001return 0
 279                 cmd_name trace2 (trace2)
 280                 exit elapsed:_TIME_ code:0
 281                 atexit elapsed:_TIME_ code:0
 282         EOF
 283         test_cmp expect actual
 284 '
 285
 286 test_expect_success 'unsafe URLs are redacted by default' '
 287         test_when_finished \
 288                 "rm -r trace.normal unredacted.normal clone clone2" &&
 289
 290         test_config_global \
 291                 "url.$(pwd).insteadOf" https://user:pwd@example.com/ &&
 292         test_config_global trace2.configParams "core.*,remote.*.url" &&
 293
 294         GIT_TRACE2="$(pwd)/trace.normal" \
 295                 git clone https://user:pwd@example.com/ clone &&
 296         ! grep user:pwd trace.normal &&
 297
 298         GIT_TRACE2_REDACT=0 GIT_TRACE2="$(pwd)/unredacted.normal" \
 299                 git clone https://user:pwd@example.com/ clone2 &&
 300         grep "start .* clone https://user:pwd@example.com" unredacted.normal &&
 301         grep "remote.origin.url=https://user:pwd@example.com" unredacted.normal
 302 '
 303
 304 test_done