Improve opa logging

[yorinasub17]

Problem

Currently, the opa eval calls for multiple files happen concurrently and this results in the output logs interleaving. This makes it hard to read the command output because it outputs JSON. See the following example from a test run:

TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66: {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:   "result": [
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:     {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:       "expressions": [
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66: {}
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66: {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:         {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:   "result": [
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "value": true,
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "text": "data.enforce_source.allow",
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:     {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "location": {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:             "row": 1,
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:             "col": 1
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:         }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:       ]
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:     }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:       "expressions": [
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:         {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "value": true,
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "text": "data.enforce_source.allow",
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           "location": {
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:   ]
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:             "row": 1,
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66: }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:             "col": 1
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:           }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:         }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:       ]
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:     }
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66:   ]
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T12:01:06-05:00 logger.go:66: }

The other issue is that the output when opa checks fail with FailUndefined is {}, which makes it hard to debug failures.

Solution

This PR implements the following:

• Update the logging so that it buffers the output and logs the entire output at once. This should be ok for opa eval calls because they happen relatively quickly compared to something like Docker or Terraform.
• Add a new flag DebugQueryDataOnError which will rerun opa eval with a larger scoped result query so that you can see all the contents of all the defined expressions, making it easier to understand what went wrong in a failure.

With these changes, the above output improves to be:

TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: Output of command `opa eval --fail -i /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/variables.json -d ../examples/terraform-opa-example/policy/enforce_source.rego data.enforce_source.allow`:
{
  "result": [
    {
      "expressions": [
        {
          "value": true,
          "text": "data.enforce_source.allow",
          "location": {
            "row": 1,
            "col": 1
          }
        }
      ]
    }
  ]
}
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: Output of command `opa eval --fail -i /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/output.json -d ../examples/terraform-opa-example/policy/enforce_source.rego data.enforce_source.allow`:
{
  "result": [
    {
      "expressions": [
        {
          "value": true,
          "text": "data.enforce_source.allow",
          "location": {
            "row": 1,
            "col": 1
          }
        }
      ]
    }
  ]
}
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: opa eval passed on file /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/variables.json (policy enforce_source.rego; query data.enforce_source.allow)
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: opa eval passed on file /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/output.json (policy enforce_source.rego; query data.enforce_source.allow)
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: Output of command `opa eval --fail -i /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/main.json -d ../examples/terraform-opa-example/policy/enforce_source.rego data.enforce_source.allow`:
{}
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: Failed opa eval on file /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/main.json (policy enforce_source.rego; query data.enforce_source.allow)
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: DEBUG: rerunning opa eval to query for full data.
TestOPAEvalTerraformModuleFailsCheck 2021-10-07T14:41:52-05:00 logger.go:66: Output of command `opa eval --fail -i /var/folders/36/ljcx66pj73zd3sq1r1tsr_300000gn/T/terratest-opa-hcl2json-423489062/main.json -d ../examples/terraform-opa-example/policy/enforce_source.rego data`:
{
  "result": [
    {
      "expressions": [
        {
          "value": {
            "enforce_source": {
              "violation": [
                "instance_types"
              ]
            }
          },
          "text": "data",
          "location": {
            "row": 1,
            "col": 1
          }
        }
      ]
    }
  ]
}

Bonus fixes

• Fix docs bug on website where it doesn't render the fail module.

[brikis98]

Nice improvement 👍

[brikis98]

LGTM!

[yorinasub17]

Thanks for review! Going to merge this in now.