From 2d5075afb8bbe53a62060d2c2028c15b653aae38 Mon Sep 17 00:00:00 2001 From: Onsi Fakhouri Date: Mon, 13 Feb 2023 13:52:21 -0700 Subject: [PATCH] lock around default report output to avoid triggering the race detector when calling By from goroutines Fixes #1134 --- .../passing_ginkgo_tests_test.go | 17 +++++++ integration/run_test.go | 18 +++---- integration/verbose_and_succinct_test.go | 10 +++- reporters/default_reporter.go | 47 +++++++++++-------- 4 files changed, 63 insertions(+), 29 deletions(-) diff --git a/integration/_fixtures/passing_ginkgo_tests_fixture/passing_ginkgo_tests_test.go b/integration/_fixtures/passing_ginkgo_tests_fixture/passing_ginkgo_tests_test.go index 896ff79f1..8fd0172ff 100644 --- a/integration/_fixtures/passing_ginkgo_tests_fixture/passing_ginkgo_tests_test.go +++ b/integration/_fixtures/passing_ginkgo_tests_fixture/passing_ginkgo_tests_test.go @@ -1,6 +1,8 @@ package passing_ginkgo_tests_test import ( + "sync" + . "github.com/onsi/ginkgo/v2" . "github.com/onsi/ginkgo/v2/integration/_fixtures/passing_ginkgo_tests_fixture" . "github.com/onsi/gomega" @@ -27,4 +29,19 @@ var _ = Describe("PassingGinkgoTests", func() { By("emitting another By") Ω(4).Should(Equal(4)) }) + + Context("when called within goroutines", func() { + It("does not trigger the race detector", func() { + wg := &sync.WaitGroup{} + wg.Add(3) + for i := 0; i < 3; i += 1 { + go func() { + By("avoiding the race detector") + wg.Done() + }() + } + wg.Wait() + }) + }) + }) diff --git a/integration/run_test.go b/integration/run_test.go index 50922aaab..6297ce5fd 100644 --- a/integration/run_test.go +++ b/integration/run_test.go @@ -34,7 +34,7 @@ var _ = Describe("Running Specs", func() { Ω(output).Should(ContainSubstring("Running Suite: Passing_ginkgo_tests Suite")) Ω(output).Should(ContainSubstring(strings.Repeat(denoter, 4))) - Ω(output).Should(ContainSubstring("SUCCESS! -- 4 Passed")) + Ω(output).Should(ContainSubstring("SUCCESS! -- 5 Passed")) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -51,7 +51,7 @@ var _ = Describe("Running Specs", func() { Ω(output).Should(ContainSubstring("Running Suite: Passing_ginkgo_tests Suite")) Ω(output).Should(ContainSubstring(strings.Repeat(denoter, 4))) - Ω(output).Should(ContainSubstring("SUCCESS! -- 4 Passed")) + Ω(output).Should(ContainSubstring("SUCCESS! -- 5 Passed")) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -268,7 +268,7 @@ var _ = Describe("Running Specs", func() { Eventually(session).Should(gexec.Exit(0)) output := string(session.Out.Contents()) - Ω(output).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs - 2 procs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s`, regexp.QuoteMeta(denoter))) + Ω(output).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs - 2 procs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s`, regexp.QuoteMeta(denoter))) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -286,7 +286,7 @@ var _ = Describe("Running Specs", func() { if nodes > 4 { nodes = nodes - 1 } - Ω(output).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs - %d procs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]?s`, nodes, regexp.QuoteMeta(denoter))) + Ω(output).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs - %d procs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]?s`, nodes, regexp.QuoteMeta(denoter))) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -341,7 +341,7 @@ var _ = Describe("Running Specs", func() { outputLines := strings.Split(output, "\n") Ω(outputLines[0]).Should(MatchRegexp(`\[\d+\] More_ginkgo_tests Suite - 2/2 specs [%s]{2} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(outputLines[1]).Should(ContainSubstring("Skipping ./no_tagged_tests (no test files)")) - Ω(outputLines[2]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) + Ω(outputLines[2]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -354,7 +354,7 @@ var _ = Describe("Running Specs", func() { outputLines := strings.Split(output, "\n") Ω(outputLines[0]).Should(MatchRegexp(`\[\d+\] More_ginkgo_tests Suite - 2/2 specs [%s]{2} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(outputLines[1]).Should(ContainSubstring("Skipping ./no_tagged_tests (no test files)")) - Ω(outputLines[2]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) + Ω(outputLines[2]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(output).Should(ContainSubstring("Test Suite Passed")) }) }) @@ -372,7 +372,7 @@ var _ = Describe("Running Specs", func() { outputLines := strings.Split(output, "\n") Ω(outputLines[0]).Should(ContainSubstring("Skipping ./no_tagged_tests (no test files)")) - Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) + Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(outputLines[2]).Should(MatchRegexp(`\[\d+\] Failing_ginkgo_tests Suite - 2/2 specs`)) Ω(output).Should(ContainSubstring(fmt.Sprintf("%s [FAILED]", denoter))) Ω(output).ShouldNot(ContainSubstring("More_ginkgo_tests Suite")) @@ -392,7 +392,7 @@ var _ = Describe("Running Specs", func() { outputLines := strings.Split(output, "\n") Ω(outputLines[0]).Should(ContainSubstring("Skipping ./no_tagged_tests (no test files)")) - Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) + Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(outputLines[2]).Should(ContainSubstring("Failed to compile does_not_compile:")) Ω(output).ShouldNot(ContainSubstring("More_ginkgo_tests Suite")) Ω(output).Should(ContainSubstring("Test Suite Failed")) @@ -412,7 +412,7 @@ var _ = Describe("Running Specs", func() { outputLines := strings.Split(output, "\n") Ω(outputLines[0]).Should(ContainSubstring("Skipping ./no_tagged_tests (no test files)")) - Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) + Ω(outputLines[1]).Should(MatchRegexp(`\[\d+\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS! \d+(\.\d+)?[muµ]s PASS`, regexp.QuoteMeta(denoter))) Ω(outputLines[2]).Should(ContainSubstring("Failed to compile does_not_compile:")) Ω(output).Should(MatchRegexp(`\[\d+\] Failing_ginkgo_tests Suite - 2/2 specs`)) Ω(output).Should(ContainSubstring(fmt.Sprintf("%s [FAILED]", denoter))) diff --git a/integration/verbose_and_succinct_test.go b/integration/verbose_and_succinct_test.go index ad565aee8..eb1087622 100644 --- a/integration/verbose_and_succinct_test.go +++ b/integration/verbose_and_succinct_test.go @@ -42,7 +42,7 @@ var _ = Describe("Verbose And Succinct Mode", func() { Eventually(session).Should(gexec.Exit(0)) output := session.Out.Contents() - Ω(output).Should(MatchRegexp(`\] Passing_ginkgo_tests Suite - 4/4 specs [%s]{4} SUCCESS!`, regexp.QuoteMeta(denoter))) + Ω(output).Should(MatchRegexp(`\] Passing_ginkgo_tests Suite - 5/5 specs [%s]{5} SUCCESS!`, regexp.QuoteMeta(denoter))) Ω(output).Should(MatchRegexp(`\] More_ginkgo_tests Suite - 2/2 specs [%s]{2} SUCCESS!`, regexp.QuoteMeta(denoter))) }) }) @@ -78,6 +78,14 @@ var _ = Describe("Verbose And Succinct Mode", func() { Ω(output).Should(ContainSubstring("emitting one By")) Ω(output).Should(ContainSubstring("emitting another By")) }) + + It("doesn't trigger the race detector", func() { + session := startGinkgo(fm.PathTo("passing_ginkgo_tests"), "--no-color", "-v", "-race") + Eventually(session).Should(gexec.Exit(0)) + output := session.Out.Contents() + + Ω(output).Should(ContainSubstring("avoiding the race detector")) + }) }) Context("with -vv", func() { diff --git a/reporters/default_reporter.go b/reporters/default_reporter.go index 1425825f7..56b7be758 100644 --- a/reporters/default_reporter.go +++ b/reporters/default_reporter.go @@ -12,6 +12,7 @@ import ( "io" "runtime" "strings" + "sync" "time" "github.com/onsi/ginkgo/v2/formatter" @@ -23,7 +24,7 @@ type DefaultReporter struct { writer io.Writer // managing the emission stream - lastChar string + lastCharWasNewline bool lastEmissionWasDelimiter bool // rendering @@ -32,6 +33,7 @@ type DefaultReporter struct { formatter formatter.Formatter runningInParallel bool + lock *sync.Mutex } func NewDefaultReporterUnderTest(conf types.ReporterConfig, writer io.Writer) *DefaultReporter { @@ -46,12 +48,13 @@ func NewDefaultReporter(conf types.ReporterConfig, writer io.Writer) *DefaultRep conf: conf, writer: writer, - lastChar: "\n", + lastCharWasNewline: true, lastEmissionWasDelimiter: false, specDenoter: "•", retryDenoter: "↺", formatter: formatter.NewWithNoColorBool(conf.NoColor), + lock: &sync.Mutex{}, } if runtime.GOOS == "windows" { reporter.specDenoter = "+" @@ -619,31 +622,37 @@ func (r *DefaultReporter) emitSource(indent uint, fc types.FunctionCall) { /* Emitting to the writer */ func (r *DefaultReporter) emit(s string) { - if len(s) > 0 { - r.lastChar = s[len(s)-1:] - r.lastEmissionWasDelimiter = false - r.writer.Write([]byte(s)) - } + r._emit(s, false, false) } func (r *DefaultReporter) emitBlock(s string) { - if len(s) > 0 { - if r.lastChar != "\n" { - r.emit("\n") - } - r.emit(s) - if r.lastChar != "\n" { - r.emit("\n") - } - } + r._emit(s, true, false) } func (r *DefaultReporter) emitDelimiter(indent uint) { - if r.lastEmissionWasDelimiter { + r._emit(r.fi(indent, "{{gray}}%s{{/}}", strings.Repeat("-", 30)), true, true) +} + +// a bit ugly - but we're trying to minimize locking on this hot codepath +func (r *DefaultReporter) _emit(s string, block bool, isDelimiter bool) { + if len(s) == 0 { + return + } + r.lock.Lock() + defer r.lock.Unlock() + if isDelimiter && r.lastEmissionWasDelimiter { return } - r.emitBlock(r.fi(indent, "{{gray}}%s{{/}}", strings.Repeat("-", 30))) - r.lastEmissionWasDelimiter = true + if block && !r.lastCharWasNewline { + r.writer.Write([]byte("\n")) + } + r.lastCharWasNewline = (s[len(s)-1:] == "\n") + r.writer.Write([]byte(s)) + if block && !r.lastCharWasNewline { + r.writer.Write([]byte("\n")) + r.lastCharWasNewline = true + } + r.lastEmissionWasDelimiter = isDelimiter } /* Rendering text */