diff --git a/core_dsl.go b/core_dsl.go index 4a14e50a8..47d2efee7 100644 --- a/core_dsl.go +++ b/core_dsl.go @@ -163,6 +163,15 @@ func GinkgoParallelProcess() int { return suiteConfig.ParallelProcess } +/* +GinkgoHelper marks the function it's called in as a test helper. When a failure occurs inside a helper function, Ginkgo will skip the helper when analyzing the stack trace to identify where the failure occurred. + +This is an alternative, simpler, mechanism to passing in a skip offset when calling Fail or using Gomega. +*/ +func GinkgoHelper() { + types.MarkAsHelper(1) +} + /* PauseOutputInterception() pauses Ginkgo's output interception. This is only relevant when running in parallel and output to stdout/stderr is being intercepted. You generally diff --git a/docs/index.md b/docs/index.md index 3b0e57cb5..b1da6ce94 100644 --- a/docs/index.md +++ b/docs/index.md @@ -1202,6 +1202,66 @@ You must remember to follow this pattern when making assertions in goroutines - When a failure occurs Ginkgo marks the current spec as failed and moves on to the next spec. If, however, you'd like to stop the entire suite when the first failure occurs you can run `ginkgo --fail-fast`. +One last thing before we move on. When a failure occurs, Ginkgo records and presents the location of the failure to help you pinpoint where to look to debug your specs. This is typically the line where the call to `Fail` was performed (or, if you're using Gomega, the line where the Gomega assertion failed). Sometimes, however, you need to control the reported location. For example, consider the case where you are using a helper function: + +```go +/* === INVALID === */ +func EnsureUserCanRead(book Book, user User) { + if book.Title == "Les Miserables" && user.Age <= 3 { + Fail("user is too young for this book") //A + } +} + +It("can read books", func() { + EnsureUserCanRead(book, user) //B + user.Read(book) +}) +``` + +Now, if the `EnsureUserCanRead` helper fails the location presented to the user will point to `//A`. Ideally, however we'd prefer that Ginkgo report `//B`. + +There are a few ways to solve for this. The first is to pass `Fail` an `offset` like so: + +```go +func EnsureUserCanRead(book Book, user User) { + if book.Title == "Les Miserables" && user.Age <= 3 { + Fail("user is too young for this book", 1) + } +} +``` + +This will tell Ginkgo to skip a stack frame when calculating the offset. In this particular case Ginkgo will report the location that called `EnsureUserCanRead`: i.e. `//B`. + +This works... however managing offset can quickly get unwieldy. For example, say we wanted to compose helpers: + +```go +func EnsureUserCanCheckout(book Book, user User) { + EnsureUserCanRead(book, user) + EnsureUserHasAccessTo(book, user) +} +``` + +in _this_ case, we'd need the offset that `EnsureUserCanRead` passes to `Fail` to be `2` instead of `1`. + +Instead of managing offsets you can use `GinkgoHelper()`: + +```go +func EnsureUserCanRead(book Book, user User) { + GinkgoHelper() + if book.Title == "Les Miserables" && user.Age <= 3 { + Fail("user is too young for this book") //note the optional offset is gone + } +} + +func EnsureUserCanCheckout(book Book, user User) { + GinkgoHelper() + EnsureUserCanRead(book, user) + EnsureUserHasAccessTo(book, user) +} +``` + +Any function in which `GinkgoHelper()` is called is tracked by Ginkgo and ignored when a failure location is being computed. This allows you to build reusable test helpers and trust that the location presented to the user will always be in the spec that called the helper, and not the helper itself. + ### Logging Output As outlined above, when a spec fails - say via a failed Gomega assertion - Ginkgo will pass the failure message passed to the `Fail` handler. Often times the failure message generated by Gomega gives you enough information to understand and resolve the spec failure. @@ -4896,6 +4956,25 @@ now, if the `It` defined in `SharedBehaviorIt` the location reported by Ginkgo w If multiple `Offset`s are provided on a given node, only the last one is used. +Lastly, since introducing `Offset` Ginkgo has introduced `GinkgoHelper()` which marks the current function as a test helper who's location should be skipped when determining the location for a node. We generally recommend using `GinkgoHelper()` instead of `Offset()` to manage how locations are computed. The above example could be rewritten as + +```go +SharedBehaviorIt := func() { + GinkgoHelper() + It("does something common and complicated", func() { + ... + }) +} + +Describe("thing A", func() { + SharedBehaviorIt() +}) + +Describe("thing B", func() { + SharedBehaviorIt() +}) +``` + #### The CodeLocation Decorator In addition to `Offset`, users can decorate nodes with a `types.CodeLocation`. `CodeLocation`s are the structs Ginkgo uses to capture location information. You can, for example, set a custom location using `types.NewCustomCodeLocation(message string)`. Now when the location of the node is emitted the passed in `message` will be printed out instead of the usual `file:line` location. diff --git a/dsl/core/core_dsl.go b/dsl/core/core_dsl.go index e62d2a1c9..b4287b773 100644 --- a/dsl/core/core_dsl.go +++ b/dsl/core/core_dsl.go @@ -28,6 +28,7 @@ var GinkgoLogr = ginkgo.GinkgoLogr var GinkgoConfiguration = ginkgo.GinkgoConfiguration var GinkgoRandomSeed = ginkgo.GinkgoRandomSeed var GinkgoParallelProcess = ginkgo.GinkgoParallelProcess +var GinkgoHelper = ginkgo.GinkgoHelper var PauseOutputInterception = ginkgo.PauseOutputInterception var ResumeOutputInterception = ginkgo.ResumeOutputInterception var RunSpecs = ginkgo.RunSpecs diff --git a/ginkgo_t_dsl.go b/ginkgo_t_dsl.go index 1beeb1144..c5a7eb94d 100644 --- a/ginkgo_t_dsl.go +++ b/ginkgo_t_dsl.go @@ -7,7 +7,7 @@ GinkgoT() implements an interface analogous to *testing.T and can be used with third-party libraries that accept *testing.T through an interface. GinkgoT() takes an optional offset argument that can be used to get the -correct line number associated with the failure. +correct line number associated with the failure - though you do not need to use this if you call GinkgoHelper() or GinkgoT().Helper() appropriately You can learn more here: https://onsi.github.io/ginkgo/#using-third-party-libraries */ diff --git a/integration/_fixtures/fail_fixture/fail_fixture_test.go b/integration/_fixtures/fail_fixture/fail_fixture_test.go index 48612c449..6be3a67cd 100644 --- a/integration/_fixtures/fail_fixture/fail_fixture_test.go +++ b/integration/_fixtures/fail_fixture/fail_fixture_test.go @@ -44,3 +44,12 @@ var _ = DescribeTable("a top level DescribeTable", }, Entry("a TableEntry constructed by Entry", 2, 3), ) + +var helper = func() { + GinkgoHelper() + Ω("a helper failed").Should(Equal("nope")) +} + +var _ = It("tracks line numbers correctly when GinkgoHelper() is called", func() { + helper() +}) diff --git a/integration/fail_test.go b/integration/fail_test.go index 41a27289a..4bea55a6d 100644 --- a/integration/fail_test.go +++ b/integration/fail_test.go @@ -38,7 +38,10 @@ var _ = Describe("Failing Specs", func() { Ω(output).Should(MatchRegexp(`a top level DescribeTable \[It\] a TableEntry constructed by Entry\n.*fail_fixture_test\.go:45`), "the output of a failing Entry should include its file path and line number") - Ω(output).Should(ContainSubstring("0 Passed | 7 Failed")) + Ω(output).Should(ContainSubstring(`a helper failed`)) + Ω(output).Should(ContainSubstring(`fail_fixture_test.go:54`), "the code location reported for the helper failure - we're testing the call to GinkgoHelper() works as expected") + + Ω(output).Should(ContainSubstring("0 Passed | 8 Failed")) }) }) diff --git a/integration/flags_test.go b/integration/flags_test.go index 03f631b22..1972136d4 100644 --- a/integration/flags_test.go +++ b/integration/flags_test.go @@ -131,8 +131,8 @@ var _ = Describe("Flags Specs", func() { output := string(session.Out.Contents()) Ω(output).Should(ContainSubstring("synchronous failures")) - Ω(output).Should(ContainSubstring("7 Specs")) - Ω(output).Should(ContainSubstring("7 Passed")) + Ω(output).Should(ContainSubstring("8 Specs")) + Ω(output).Should(ContainSubstring("8 Passed")) Ω(output).Should(ContainSubstring("0 Failed")) }) diff --git a/internal/internal_integration/decorations_test.go b/internal/internal_integration/decorations_test.go index e90d64581..6caadcee3 100644 --- a/internal/internal_integration/decorations_test.go +++ b/internal/internal_integration/decorations_test.go @@ -14,12 +14,17 @@ var _ = Describe("Decorations test", func() { customIt := func() { It("is-offset", rt.T("is-offset"), Offset(1)) } + otherCustomIt := func() { + GinkgoHelper() + It("is-also-offset", rt.T("is-also-offset")) + } var countFlaky = 0 var countRepeat = 0 success, _ := RunFixture("happy-path decoration test", func() { Describe("top-level-container", func() { clForOffset = types.NewCodeLocation(0) customIt() + otherCustomIt() It("flaky", FlakeAttempts(4), rt.T("flaky", func() { countFlaky += 1 outputInterceptor.AppendInterceptedOutput("so flaky\n") @@ -56,6 +61,7 @@ var _ = Describe("Decorations test", func() { It("runs all the test nodes in the expected order", func() { Ω(rt).Should(HaveTracked( "is-offset", + "is-also-offset", "flaky", "flaky", "flaky", "flaky-never-passes", "flaky-never-passes", "flaky-skips", @@ -72,6 +78,13 @@ var _ = Describe("Decorations test", func() { }) }) + Describe("GinkgoHelper", func() { + It("correctly skips through the stack trace when computing the codelocation", func() { + clForOffset.LineNumber = clForOffset.LineNumber + 2 + Ω(reporter.Did.Find("is-also-offset").LeafNodeLocation).Should(Equal(clForOffset)) + }) + }) + Describe("FlakeAttempts", func() { It("reruns specs until they pass or until the number of flake attempts is exhausted, but does not rerun skipped specs", func() { Ω(reporter.Did.Find("flaky")).Should(HavePassed(NumAttempts(3), CapturedStdOutput("so flaky\nso flaky\nso flaky\n"), CapturedGinkgoWriterOutput("so tasty\nso tasty\nso tasty\n"))) diff --git a/internal/testingtproxy/testing_t_proxy.go b/internal/testingtproxy/testing_t_proxy.go index 2f42b2642..c797c95d4 100644 --- a/internal/testingtproxy/testing_t_proxy.go +++ b/internal/testingtproxy/testing_t_proxy.go @@ -81,7 +81,7 @@ func (t *ginkgoTestingTProxy) Fatalf(format string, args ...interface{}) { } func (t *ginkgoTestingTProxy) Helper() { - // No-op + types.MarkAsHelper(1) } func (t *ginkgoTestingTProxy) Log(args ...interface{}) { diff --git a/internal/testingtproxy/testingtproxy_test.go b/internal/testingtproxy/testingtproxy_test.go index 618f160fb..4fa3de8b7 100644 --- a/internal/testingtproxy/testingtproxy_test.go +++ b/internal/testingtproxy/testingtproxy_test.go @@ -2,6 +2,7 @@ package testingtproxy_test import ( "os" + "runtime" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" @@ -165,7 +166,15 @@ var _ = Describe("Testingtproxy", func() { }) It("ignores Helper", func() { - GinkgoT().Helper() //is a no-op + cl := func() types.CodeLocation { + GinkgoT().Helper() + return types.NewCodeLocation(0) + }() // this is the expected line + _, fname, lnumber, _ := runtime.Caller(0) + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber - 1, + })) }) It("supports Log", func() { diff --git a/table_dsl.go b/table_dsl.go index 683674462..ac9b7abb5 100644 --- a/table_dsl.go +++ b/table_dsl.go @@ -13,7 +13,7 @@ import ( /* The EntryDescription decorator allows you to pass a format string to DescribeTable() and Entry(). This format string is used to generate entry names via: - fmt.Sprintf(formatString, parameters...) + fmt.Sprintf(formatString, parameters...) where parameters are the parameters passed into the entry. @@ -32,19 +32,20 @@ DescribeTable describes a table-driven spec. For example: - DescribeTable("a simple table", - func(x int, y int, expected bool) { - Ω(x > y).Should(Equal(expected)) - }, - Entry("x > y", 1, 0, true), - Entry("x == y", 0, 0, false), - Entry("x < y", 0, 1, false), - ) + DescribeTable("a simple table", + func(x int, y int, expected bool) { + Ω(x > y).Should(Equal(expected)) + }, + Entry("x > y", 1, 0, true), + Entry("x == y", 0, 0, false), + Entry("x < y", 0, 1, false), + ) You can learn more about DescribeTable here: https://onsi.github.io/ginkgo/#table-specs And can explore some Table patterns here: https://onsi.github.io/ginkgo/#table-specs-patterns */ func DescribeTable(description string, args ...interface{}) bool { + GinkgoHelper() generateTable(description, args...) return true } @@ -53,6 +54,7 @@ func DescribeTable(description string, args ...interface{}) bool { You can focus a table with `FDescribeTable`. This is equivalent to `FDescribe`. */ func FDescribeTable(description string, args ...interface{}) bool { + GinkgoHelper() args = append(args, internal.Focus) generateTable(description, args...) return true @@ -62,6 +64,7 @@ func FDescribeTable(description string, args ...interface{}) bool { You can mark a table as pending with `PDescribeTable`. This is equivalent to `PDescribe`. */ func PDescribeTable(description string, args ...interface{}) bool { + GinkgoHelper() args = append(args, internal.Pending) generateTable(description, args...) return true @@ -95,26 +98,29 @@ If you want to generate interruptible specs simply write a Table function that a You can learn more about Entry here: https://onsi.github.io/ginkgo/#table-specs */ func Entry(description interface{}, args ...interface{}) TableEntry { + GinkgoHelper() decorations, parameters := internal.PartitionDecorations(args...) - return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(1)} + return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(0)} } /* You can focus a particular entry with FEntry. This is equivalent to FIt. */ func FEntry(description interface{}, args ...interface{}) TableEntry { + GinkgoHelper() decorations, parameters := internal.PartitionDecorations(args...) decorations = append(decorations, internal.Focus) - return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(1)} + return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(0)} } /* You can mark a particular entry as pending with PEntry. This is equivalent to PIt. */ func PEntry(description interface{}, args ...interface{}) TableEntry { + GinkgoHelper() decorations, parameters := internal.PartitionDecorations(args...) decorations = append(decorations, internal.Pending) - return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(1)} + return TableEntry{description: description, decorations: decorations, parameters: parameters, codeLocation: types.NewCodeLocation(0)} } /* @@ -126,7 +132,8 @@ var contextType = reflect.TypeOf(new(context.Context)).Elem() var specContextType = reflect.TypeOf(new(SpecContext)).Elem() func generateTable(description string, args ...interface{}) { - cl := types.NewCodeLocation(2) + GinkgoHelper() + cl := types.NewCodeLocation(0) containerNodeArgs := []interface{}{cl} entries := []TableEntry{} diff --git a/types/code_location.go b/types/code_location.go index 129109183..9cd576817 100644 --- a/types/code_location.go +++ b/types/code_location.go @@ -7,6 +7,7 @@ import ( "runtime" "runtime/debug" "strings" + "sync" ) type CodeLocation struct { @@ -38,6 +39,73 @@ func (codeLocation CodeLocation) ContentsOfLine() string { return lines[codeLocation.LineNumber-1] } +type codeLocationLocator struct { + pcs map[uintptr]bool + helpers map[string]bool + lock *sync.Mutex +} + +func (c *codeLocationLocator) addHelper(pc uintptr) { + c.lock.Lock() + defer c.lock.Unlock() + + if c.pcs[pc] { + return + } + c.lock.Unlock() + f := runtime.FuncForPC(pc) + c.lock.Lock() + if f == nil { + return + } + c.helpers[f.Name()] = true + c.pcs[pc] = true +} + +func (c *codeLocationLocator) hasHelper(name string) bool { + c.lock.Lock() + defer c.lock.Unlock() + return c.helpers[name] +} + +func (c *codeLocationLocator) getCodeLocation(skip int) CodeLocation { + pc := make([]uintptr, 40) + n := runtime.Callers(skip+2, pc) + if n == 0 { + return CodeLocation{} + } + pc = pc[:n] + frames := runtime.CallersFrames(pc) + for { + frame, more := frames.Next() + if !c.hasHelper(frame.Function) { + return CodeLocation{FileName: frame.File, LineNumber: frame.Line} + } + if !more { + break + } + } + return CodeLocation{} +} + +var clLocator = &codeLocationLocator{ + pcs: map[uintptr]bool{}, + helpers: map[string]bool{}, + lock: &sync.Mutex{}, +} + +// MarkAsHelper is used by GinkgoHelper to mark the caller (appropriately offset by skip)as a helper. You can use this directly if you need to provide an optional `skip` to mark functions further up the call stack as helpers. +func MarkAsHelper(optionalSkip ...int) { + skip := 1 + if len(optionalSkip) > 0 { + skip += optionalSkip[0] + } + pc, _, _, ok := runtime.Caller(skip) + if ok { + clLocator.addHelper(pc) + } +} + func NewCustomCodeLocation(message string) CodeLocation { return CodeLocation{ CustomMessage: message, @@ -45,14 +113,13 @@ func NewCustomCodeLocation(message string) CodeLocation { } func NewCodeLocation(skip int) CodeLocation { - _, file, line, _ := runtime.Caller(skip + 1) - return CodeLocation{FileName: file, LineNumber: line} + return clLocator.getCodeLocation(skip + 1) } func NewCodeLocationWithStackTrace(skip int) CodeLocation { - _, file, line, _ := runtime.Caller(skip + 1) - stackTrace := PruneStack(string(debug.Stack()), skip+1) - return CodeLocation{FileName: file, LineNumber: line, FullStackTrace: stackTrace} + cl := clLocator.getCodeLocation(skip + 1) + cl.FullStackTrace = PruneStack(string(debug.Stack()), skip+1) + return cl } // PruneStack removes references to functions that are internal to Ginkgo diff --git a/types/code_location_test.go b/types/code_location_test.go index 19c38e775..da5d76e9d 100644 --- a/types/code_location_test.go +++ b/types/code_location_test.go @@ -1,6 +1,7 @@ package types_test import ( + "fmt" "runtime" . "github.com/onsi/ginkgo/v2" @@ -9,63 +10,104 @@ import ( ) var _ = Describe("CodeLocation", func() { - var codeLocation types.CodeLocation - var expectedFileName string - var expectedLineNumber int - - caller0 := func() { - codeLocation = types.NewCodeLocation(1) + clWithSkip := func(skip int) types.CodeLocation { + return types.NewCodeLocation(skip) } - caller1 := func() { - _, expectedFileName, expectedLineNumber, _ = runtime.Caller(0) - expectedLineNumber += 2 - caller0() + helperFunction := func() types.CodeLocation { + GinkgoHelper() + return types.NewCodeLocation(0) } - BeforeEach(func() { - caller1() - }) + Describe("Creating CodeLocations", func() { + Context("when skip is 0", func() { + It("returns the location at which types.NewCodeLocation was called", func() { + _, fname, lnumber, _ := runtime.Caller(0) + cl := types.NewCodeLocation(0) + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber + 1, + })) + }) + }) + + Context("when skip is > 0", func() { + It("returns the appropriate location from the stack", func() { + _, fname, lnumber, _ := runtime.Caller(0) + cl := clWithSkip(1) + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber + 1, + })) + + _, fname, lnumber, _ = runtime.Caller(0) + cl = func() types.CodeLocation { + return clWithSkip(2) + }() // this is the line that's expected + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber + 3, + })) + }) + }) + + Describe("when a function has been marked as a helper", func() { + It("does not include that function when generating a code location", func() { + _, fname, lnumber, _ := runtime.Caller(0) + cl := helperFunction() + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber + 1, + })) - It("should use the passed in skip parameter to pick out the correct file & line number", func() { - Ω(codeLocation.FileName).Should(Equal(expectedFileName)) - Ω(codeLocation.LineNumber).Should(Equal(expectedLineNumber)) - Ω(codeLocation.FullStackTrace).Should(BeZero()) + _, fname, lnumber, _ = runtime.Caller(0) + cl = func() types.CodeLocation { + GinkgoHelper() + return func() types.CodeLocation { + types.MarkAsHelper() + return helperFunction() + }() + }() // this is the line that's expected + Ω(cl).Should(Equal(types.CodeLocation{ + FileName: fname, + LineNumber: lnumber + 7, + })) + }) + }) }) Describe("stringer behavior", func() { It("should stringify nicely", func() { - Ω(codeLocation.String()).Should(ContainSubstring("code_location_test.go:%d", expectedLineNumber)) + _, fname, lnumber, _ := runtime.Caller(0) + cl := types.NewCodeLocation(0) + Ω(cl.String()).Should(Equal(fmt.Sprintf("%s:%d", fname, lnumber+1))) }) }) Describe("with a custom message", func() { - BeforeEach(func() { - codeLocation = types.NewCustomCodeLocation("I'm right here.") - }) - It("emits the custom message", func() { - Ω(codeLocation.String()).Should(Equal("I'm right here.")) + cl := types.NewCustomCodeLocation("I'm right here.") + Ω(cl.String()).Should(Equal("I'm right here.")) }) }) Describe("Fetching the line from the file in question", func() { It("works", func() { - codeLocation = types.NewCodeLocation(0) - codeLocation.LineNumber = codeLocation.LineNumber - 2 - Ω(codeLocation.ContentsOfLine()).Should(Equal("\tDescribe(\"Fetching the line from the file in question\", func() {")) + cl := types.NewCodeLocation(0) + cl.LineNumber = cl.LineNumber - 2 + Ω(cl.ContentsOfLine()).Should(Equal("\tDescribe(\"Fetching the line from the file in question\", func() {")) }) It("returns empty string if the line is not found or is out of bounds", func() { - codeLocation = types.CodeLocation{ + cl := types.CodeLocation{ FileName: "foo.go", LineNumber: 0, } - Ω(codeLocation.ContentsOfLine()).Should(BeZero()) + Ω(cl.ContentsOfLine()).Should(BeZero()) - codeLocation = types.NewCodeLocation(0) - codeLocation.LineNumber = codeLocation.LineNumber + 1000000 - Ω(codeLocation.ContentsOfLine()).Should(BeZero()) + cl = types.NewCodeLocation(0) + cl.LineNumber = cl.LineNumber + 1000000 + Ω(cl.ContentsOfLine()).Should(BeZero()) }) })