diff --git a/docs/index.md b/docs/index.md index e5f3dcc75..52cc2585a 100644 --- a/docs/index.md +++ b/docs/index.md @@ -2823,7 +2823,9 @@ DescribeTable("contrived context-value example", #### SpecContext and Progress Reports -_Coming Soon_ +`SpecContext` provides an extension point that enables consumers to attach additional information to Progress Reports that Ginkgo generates. This is accomplished by calling `ctx.AttachProgressReporter(f)` where `f` has the signature `func() string`. Once attached, the function will be called whenever a Progress Report needs to be generated (e.g. due to a user request via `SIGINFO`/`SIGUSR1` or via an interrupt or timeout). `ctx.AttachProgressReporter` returns a detach function with signature `func()` that can be called to detach the attached progress reporter. Becuase these progress reporters are attached to the passed-in `SpecContext` they only remain attached for the lifecycle of the context: i.e. the current node. + +While users of Ginkgo can provide their own custom progress reporters the intent behind this extension point is to allow deeper integration between Ginkgo and third-party libraries, specifically Gomega. Whenever Gomega's `Eventually` is passed a `SpecContext` it automatically registers a progress reporter. This reporter will provide the latest state of the `Eventually` matcher - enabling users to get insight into where and why an `Eventually` might be stuck simply by asking for a Progress Report. ### Interrupting, Aborting, and Timing Out Suites diff --git a/internal/internal_integration/interrupt_and_timeout_test.go b/internal/internal_integration/interrupt_and_timeout_test.go index 19bd91e32..584b8a5d6 100644 --- a/internal/internal_integration/interrupt_and_timeout_test.go +++ b/internal/internal_integration/interrupt_and_timeout_test.go @@ -60,6 +60,7 @@ var _ = Describe("Interrupts and Timeouts", func() { summary := reporter.Did.FindByLeafNodeType(types.NodeTypeBeforeSuite) Ω(summary.State).Should(Equal(types.SpecStateInterrupted)) Ω(summary.Failure.Message).Should(ContainSubstring("Interrupted by User")) + Ω(summary.Failure.ProgressReport.Message).Should(Equal("{{bold}}This is the Progress Report generated when the interrupt was received:{{/}}")) Ω(summary.Failure.ProgressReport.CurrentNodeType).Should(Equal(types.NodeTypeBeforeSuite)) }) @@ -624,6 +625,7 @@ var _ = Describe("Interrupts and Timeouts", func() { It("A", rt.TSC("A", func(c SpecContext) { <-c.Done() rt.Run("A-cancelled") + Fail("subsequent failure message") }), NodeTimeout(time.Millisecond*100)) }) @@ -659,7 +661,7 @@ var _ = Describe("Interrupts and Timeouts", func() { "bef", "E", "aft", )) - Ω(reporter.Did.Find("A")).Should(HaveTimedOut()) + Ω(reporter.Did.Find("A")).Should(HaveTimedOut("This spec timed out and reported the following failure after the timeout:\n\nsubsequent failure message")) Ω(reporter.Did.Find("B")).Should(HaveTimedOut()) Ω(reporter.Did.Find("C")).Should(HaveTimedOut()) Ω(reporter.Did.Find("D")).Should(HavePassed()) @@ -677,6 +679,7 @@ var _ = Describe("Interrupts and Timeouts", func() { It("attaches progress reports to the timout failures", func() { Ω(reporter.Did.Find("A").Failure.ProgressReport.LeafNodeText).Should(Equal("A")) + Ω(reporter.Did.Find("A").Failure.ProgressReport.Message).Should(Equal("{{bold}}This is the Progress Report generated when the timeout occurred:{{/}}")) Ω(reporter.Did.Find("B").Failure.ProgressReport.LeafNodeText).Should(Equal("B")) Ω(reporter.Did.Find("C").Failure.ProgressReport.LeafNodeText).Should(Equal("C")) Ω(reporter.Did.Find("D").Failure.ProgressReport).Should(BeZero()) @@ -879,9 +882,8 @@ var _ = Describe("Interrupts and Timeouts", func() { success, _ := RunFixture(CurrentSpecReport().LeafNodeText, func() { Context("container", func() { It("A", rt.TSC("A", func(c SpecContext) { - Eventually(func() string { - return "foo" - }).WithTimeout(time.Hour).WithContext(c).Should(Equal("bar")) + cl = types.NewCodeLocation(0) + Eventually(func() string { return "foo" }).WithTimeout(time.Hour).WithContext(c).Should(Equal("bar")) rt.Run("A-dont-see") //never see this because Eventually fails which panics and ends execution }), SpecTimeout(time.Millisecond*200)) }) @@ -891,7 +893,9 @@ var _ = Describe("Interrupts and Timeouts", func() { It("doesn't get stuck because Eventually will exit and it includes the additional report provided by eventually", func() { Ω(rt).Should(HaveTracked("A")) - Ω(reporter.Did.Find("A")).Should(HaveTimedOut()) + Ω(reporter.Did.Find("A")).Should(HaveTimedOut(clLine(1))) + Ω(reporter.Did.Find("A").Failure.Message).Should(MatchRegexp(`This spec timed out and reported the following failure after the timeout:\n\nContext was cancelled after .*\nExpected\n : foo\nto equal\n : bar`)) + Ω(reporter.Did.Find("A").Failure.ProgressReport.Message).Should(Equal("{{bold}}This is the Progress Report generated when the timeout occurred:{{/}}")) Ω(reporter.Did.Find("A").Failure.ProgressReport.AdditionalReports).Should(ConsistOf("Expected\n : foo\nto equal\n : bar")) }) }) diff --git a/internal/internal_integration/progress_report_test.go b/internal/internal_integration/progress_report_test.go index 8937b0d64..60df37cd3 100644 --- a/internal/internal_integration/progress_report_test.go +++ b/internal/internal_integration/progress_report_test.go @@ -34,6 +34,7 @@ var _ = Describe("Progress Reporting", func() { It("emits progress when asked and includes source code", func() { Ω(reporter.ProgressReports).Should(HaveLen(1)) pr := reporter.ProgressReports[0] + Ω(pr.Message).Should(Equal("{{bold}}You've requested a progress report:{{/}}")) Ω(pr.CurrentNodeType).Should(Equal(types.NodeTypeBeforeSuite)) Ω(pr.LeafNodeLocation).Should(Equal(clLine(-1))) Ω(pr.CurrentStepText).Should(Equal("")) @@ -293,6 +294,7 @@ var _ = Describe("Progress Reporting", func() { Ω(len(reporter.ProgressReports)).Should(BeNumerically(">", 1)) for _, pr := range reporter.ProgressReports { + Ω(pr.Message).Should(Equal("{{bold}}Automatically polling progress:{{/}}")) Ω(pr.ContainerHierarchyTexts).Should(ConsistOf("a container")) Ω(pr.LeafNodeLocation).Should(Equal(clLine(-1))) Ω(pr.LeafNodeText).Should(Equal("A")) diff --git a/internal/suite.go b/internal/suite.go index 91a512a77..efb1ac4d1 100644 --- a/internal/suite.go +++ b/internal/suite.go @@ -293,7 +293,7 @@ func (suite *Suite) generateProgressReport(fullReport bool) types.ProgressReport func (suite *Suite) handleProgressSignal() { report := suite.generateProgressReport(false) - report.Message = "You've requested a progress report:" + report.Message = "{{bold}}You've requested a progress report:{{/}}" suite.emitProgressReport(report) } @@ -772,10 +772,18 @@ func (suite *Suite) runNode(node Node, specDeadline time.Time, text string) (typ select { case outcomeFromRun := <-outcomeC: failureFromRun := <-failureC - if outcome != types.SpecStateInvalid { - // we've already timed out or been interrupted. we just managed to actually exit + if outcome == types.SpecStateInterrupted { + // we've already been interrupted. we just managed to actually exit // before the grace period elapsed return outcome, failure + } else if outcome == types.SpecStateTimeout { + // we've already timed out. we just managed to actually exit + // before the grace period elapsed. if we have a failure message we should include it + if outcomeFromRun != types.SpecStatePassed { + failure.Location, failure.ForwardedPanic = failureFromRun.Location, failureFromRun.ForwardedPanic + failure.Message = "This spec timed out and reported the following failure after the timeout:\n\n" + failureFromRun.Message + } + return outcome, failure } if outcomeFromRun.Is(types.SpecStatePassed) { return outcomeFromRun, types.Failure{} @@ -795,6 +803,7 @@ func (suite *Suite) runNode(node Node, specDeadline time.Time, text string) (typ outcome = types.SpecStateTimeout failure.Message, failure.Location = "Timeout", node.CodeLocation failure.ProgressReport = suite.generateProgressReport(false).WithoutCapturedGinkgoWriterOutput() + failure.ProgressReport.Message = "{{bold}}This is the Progress Report generated when the timeout occurred:{{/}}" deadlineChannel = nil // tell the spec to stop. it's important we generate the progress report first to make sure we capture where // the spec is actually stuck @@ -810,6 +819,7 @@ func (suite *Suite) runNode(node Node, specDeadline time.Time, text string) (typ failure.Message, failure.Location = interruptStatus.Message(), node.CodeLocation if interruptStatus.ShouldIncludeProgressReport() { failure.ProgressReport = suite.generateProgressReport(true).WithoutCapturedGinkgoWriterOutput() + failure.ProgressReport.Message = "{{bold}}This is the Progress Report generated when the interrupt was received:{{/}}" } } @@ -844,7 +854,9 @@ func (suite *Suite) runNode(node Node, specDeadline time.Time, text string) (typ return outcome, failure } case <-emitProgressNow: - suite.emitProgressReport(suite.generateProgressReport(false)) + report := suite.generateProgressReport(false) + report.Message = "{{bold}}Automatically polling progress:{{/}}" + suite.emitProgressReport(report) if pollProgressInterval > 0 { progressPoller.Reset(pollProgressInterval) } diff --git a/reporters/default_reporter.go b/reporters/default_reporter.go index 0b87fb997..4a439592a 100644 --- a/reporters/default_reporter.go +++ b/reporters/default_reporter.go @@ -248,7 +248,6 @@ func (r *DefaultReporter) DidRun(report types.SpecReport) { if !report.Failure.ProgressReport.IsZero() { r.emitBlock("\n") - r.emitBlock(r.fi(1, highlightColor+"Progress Report{{/}}")) r.emitProgressReport(1, false, report.Failure.ProgressReport) } } @@ -382,14 +381,14 @@ func (r *DefaultReporter) emitProgressReport(indent uint, emitGinkgoWriterOutput if len(report.AdditionalReports) > 0 { r.emit("\n") - r.emitBlock(r.fi(indent, "{{gray}}Begin Additional Progress Reporst >>{{/}}")) + r.emitBlock(r.fi(indent, "{{gray}}Begin Additional Progress Reports >>{{/}}")) for i, additionalReport := range report.AdditionalReports { r.emit(r.fi(indent+1, additionalReport)) if i < len(report.AdditionalReports)-1 { r.emitBlock(r.fi(indent+1, "{{gray}}%s{{/}}", strings.Repeat("-", 10))) } } - r.emitBlock(r.fi(indent, "{{gray}}<< End Additional Progress Report{{/}}")) + r.emitBlock(r.fi(indent, "{{gray}}<< End Additional Progress Reports{{/}}")) } highlightedGoroutines := report.HighlightedGoroutines() diff --git a/reporters/default_reporter_test.go b/reporters/default_reporter_test.go index 80121ca1d..b809181ce 100644 --- a/reporters/default_reporter_test.go +++ b/reporters/default_reporter_test.go @@ -1120,7 +1120,6 @@ var _ = Describe("DefaultReporter", func() { " WITH DETAILS{{/}}", " {{orange}}In {{bold}}[JustBeforeEach]{{/}}{{orange}} at: {{bold}}"+cl4.String()+"{{/}}", "", - " {{orange}}Progress Report{{/}}", " In {{bold}}{{orange}}[BeforeSuite]{{/}} (Node Runtime: 3s)", " {{gray}}cl1.go:37{{/}}", DELIMITER, @@ -1157,7 +1156,6 @@ var _ = Describe("DefaultReporter", func() { " WITH DETAILS{{/}}", " {{orange}}In {{bold}}[JustBeforeEach]{{/}}{{orange}} at: {{bold}}"+cl4.String()+"{{/}}", "", - " {{orange}}Progress Report{{/}}", " In {{bold}}{{orange}}[BeforeSuite]{{/}} (Node Runtime: 3s)", " {{gray}}cl1.go:37{{/}}", DELIMITER, @@ -1769,9 +1767,9 @@ var _ = Describe("DefaultReporter", func() { " {{gray}}F3(){{/}}", " {{gray}}fileC:9{{/}}", "", - " {{gray}}Begin Additional Progress Reporst >>{{/}}", + " {{gray}}Begin Additional Progress Reports >>{{/}}", " {{blue}}Report 1{{/}}", - " {{gray}}<< End Additional Progress Report{{/}}", + " {{gray}}<< End Additional Progress Reports{{/}}", "", " {{bold}}{{underline}}Goroutines of Interest{{/}}", " {{orange}}goroutine 17 [sleeping]{{/}}", @@ -1816,11 +1814,11 @@ var _ = Describe("DefaultReporter", func() { " {{gray}}F3(){{/}}", " {{gray}}fileC:9{{/}}", "", - " {{gray}}Begin Additional Progress Reporst >>{{/}}", + " {{gray}}Begin Additional Progress Reports >>{{/}}", " {{blue}}Report 1{{/}}", " {{gray}}----------{{/}}", " {{green}}Report 2{{/}}", - " {{gray}}<< End Additional Progress Report{{/}}", + " {{gray}}<< End Additional Progress Reports{{/}}", "", " {{bold}}{{underline}}Goroutines of Interest{{/}}", " {{orange}}goroutine 17 [sleeping]{{/}}",