Skip to content

Fix coloured log output in logutil package of secure common library

Summary

Secure analyzer projects use the logutil package to output coloured log messages. The code responsible for formatting these log messages currently includes the newline character in the coloured output.

This code has been functioning as expected for quite a while, however, we've recently run into a situation where it causes an issue.

When Add junit report for Go tests (gitlab-org/security-products/ci-templates!326 - merged) was merged, it added gotestsum to the go test job, which has resulted in failures in the job output of any Go-based analyzer or package that outputs coloured log messages, for example:

=== FAIL: . TestToolExecutionNotifications/testdata/reports/semgrep_js_syntax_error.sarif (unknown)
[WARN] [2022-09-23T17:29:28Z] ▶ tool notification warning: Syntax error Semgrep Core WARN - Syntax error: When running eslint.detect-non-literal-require on /builds/gitlab-com/gl-security/engineering-and-research/gib/reports/theme/static/js/chart.js: `5:` was unexpected

These failures do not cause the go test job to fail, however, they cause gotestsum to incorrectly populate the test widget in the MR with false positive failures:

The root cause of the issue is that gotestsum is interpreting coloured log output which has been formatted by common/logutil/format.go as a failure, as described here. The reason for this behaviour is due to the fact that the common/logutil/format.go implementation currently includes the newline character before terminating the colour escape sequence.

Steps to reproduce

  1. Create an MR in any of the secure analyzer projects whose test output includes log messages

  2. View the output for the go test job in the pipeline for the MR, and notice that there are failures reported by gotestsum, for example:

    === RUN   TestToolExecutionNotifications/testdata/reports/semgrep_nonmatching_nosem.sarif
[WARN] [2022-09-23T17:29:28Z] ▶ tool notification warning: SemgrepError found 'nosem' comment with id 'bandit.B502', but no corresponding rule trying 'bandit.B501'
--- PASS: TestToolExecutionNotifications (0.01s)
    --- PASS: TestToolExecutionNotifications/testdata/reports/semgrep_invalid_config.sarif (0.00s)
    --- PASS: TestToolExecutionNotifications/testdata/reports/semgrep_js_syntax_error.sarif (0.00s)
    --- PASS: TestToolExecutionNotifications/testdata/reports/semgrep_nonmatching_nosem.sarif (0.00s)
=== FAIL: . TestToolExecutionNotifications/testdata/reports/semgrep_invalid_config.sarif (unknown)
DONE 76 tests, 3 failures in 28.916s

  3. View the MR test widget and notice that false positive test failures have been reported:

What is the current bug behavior?

gotestsum produces failure messages in the job log output, and therefore the MR test widget shows false-positive errors.

What is the expected correct behavior?

gotestsum should succeed and not produce any errors, and therefore the MR test widget should be empty.

Implementation plan

  1. Update the logutil package of the common project to avoid colouring the \n (newline) character in log messages

  2. Update all the secure analyzer projects that use the logutil package to use the new version of the common library updated in step 1. above.

    Note: updating the above analyzers to the most recent version of the common package should be a small change, however, it can easily become complicated due to the fact that some of these analyzers are using older versions of the report package, which means the expectations are out of date and don't include new fields such as scan.analyzer. See this MR in the gosec project for an example of how this task became much more complicated.

The following analyers are still using common/v2 and need to first be upgraded to common/v3 before we can fix this bug

/cc @theoretick @sam.white @brytannia

Edited by Adam Cohen