t/t0212-trace2-event.sh

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