Repository: gavv/httpexpect
Pull request #396 (2023-04-09 19:10:20)

add stacktrace to chain and formatted data
https://github.com/gavv/httpexpect/issues/160

* add `EnableStacktrace`
* add `Stacktrace` on fail in chain
* add `Stacktrace` to `FormatData`

diPhantxm: Hey @gavv. I decided to add Stacktrace to chain and fill it when fail() called. chain_test started failing because of comparing assertionFailure in tests. Should I remake tests to make it not compare `Stacktrace` or was it a bad idea to add to chain?
gavv: > Hey @gavv. I decided to add Stacktrace to chain and fill it when fail() called. chain_test started failing because of comparing assertionFailure in tests. Should I remake tests to make it not compare `Stacktrace` or was it a bad idea to add to chain?

This is a good idea indeed, this way trace would be much more convenient.
coveralls: 
[![Coverage Status](https://coveralls.io/builds/58738796/badge)](https://coveralls.io/builds/58738796)

Coverage: 95.675% (+0.003%) from 95.672% when pulling **76c87b7a40e617f5982725f6d084f38a6d54db36 on diPhantxm:feature/enable-stacktrace-flag** into **77cce299a5f7100194c81de3d94b68ef94d25859 on gavv:master**.

diPhantxm: I think it's done. Please check `defaultFailureTemplate` for formatting stacktrace.

Maybe there is a point to think about shortening stacktrace if it's too long.
gavv: I've played a bit with this patch and I think it may be convenient to resemble behavior of testify to produce a more compact trace. It is implemented here: https://github.com/stretchr/testify/blob/c5fc9d6b6b21ea89be8480c0dc35e2977ab988f6/assert/assertions.go#L147

If we'll use assert.CallerInfo() instead of debug.Stack(), the stack will look like this:

```
        <error message>
        
        test name: TestBlah

        trace:
          chain.go:442
          array.go:719
          report_test.go:380

        assertion:
          Request("GET").Expect().JSON().Array().IsEmpty()
        
        actual value:
          <blah>
        
        reference value:
         <blah>
```

which is very compact, fits the style of httpexpect output, and looks usual to testify users.

However, it loses some information compared to original trace, and some users may prefer to see the full trace. So I'd make it configurable - replace EnableStacktrace boolean with enum of three values: disabled, full, and compact.

For compact mode, if feasible, I'd even reimplement assert.CallerInfo() and use the following format instead:

```
module/file:line struct.method()
```

so instead of:

```
array.go:719
```

it would be:

```
httpexpect/v2/array.go:719 Array.IsEmpty()
```

IMHO this is the best compromise between providing enough information and keeping it compact.

---

What do you think? Do you find these ideas useful? Would you like to implement some of them in this PR, or should I create a separate issue?
diPhantxm: > I've played a bit with this patch and I think it may be convenient to resemble behavior of testify to produce a more compact trace. It is implemented here: https://github.com/stretchr/testify/blob/c5fc9d6b6b21ea89be8480c0dc35e2977ab988f6/assert/assertions.go#L147
> 
> If we'll use assert.CallerInfo() instead of debug.Stack(), the stack will look like this:
> 
> ```
>         <error message>
>         
>         test name: TestBlah
> 
>         trace:
>           chain.go:442
>           array.go:719
>           report_test.go:380
> 
>         assertion:
>           Request("GET").Expect().JSON().Array().IsEmpty()
>         
>         actual value:
>           <blah>
>         
>         reference value:
>          <blah>
> ```
> 
> which is very compact, fits the style of httpexpect output, and looks usual to testify users.
> 
> However, it loses some information compared to original trace, and some users may prefer to see the full trace. So I'd make it configurable - replace EnableStacktrace boolean with enum of three values: disabled, full, and compact.
> 
> For compact mode, if feasible, I'd even reimplement assert.CallerInfo() and use the following format instead:
> 
> ```
> module/file:line struct.method()
> ```
> 
> so instead of:
> 
> ```
> array.go:719
> ```
> 
> it would be:
> 
> ```
> httpexpect/v2/array.go:719 Array.IsEmpty()
> ```
> 
> IMHO this is the best compromise between providing enough information and keeping it compact.
> 
> What do you think? Do you find these ideas useful? Would you like to implement some of them in this PR, or should I create a separate issue?

TBH I don't see much difference between compact and full modes. `file:line` format is not so useful, because you may have multiple files with the same name but in different packages, and I don't think we should make people worry about switching modes. I agree `debug.Stack()` provides too much info and it doesn't look nice, so I would stay only with full format you provided upper `httpexpect/v2/array.go:719 Array.IsEmpty()`
I can implement this feature in this pr.
Let me know what we're doing here
gavv: > file:line format is not so useful, because you may have multiple files with the same name but in different packages

Agree

> I can implement this feature in this pr.
Let me know what we're doing here

Awesome, thanks! 

> I don't think we should make people worry about switching modes.

I feel that supporting stanard format makes sense just because it's common and complete. Someone may be just used to it, someone may want absolute paths, someone may want to use tools like panicparse or maybe their editor understands this trace format, etc. Also having unprocessed trace may be useful to debug httpexpect itself. 

We could add it later. Could you use enum instead of boolean? This will allow us to add formats in future, doesn't matter if this pr will implement 1 or 2.
gavv: Another little thought. Since we'll collect caller info and then format it, we can store caller info instead of formatted string in AssertionFailure, and do formatting in DefaultFormatter.

First, it's just logical, and second, it will give us additional flexibility for free: user will be able to implement their own formatting when using custom formatter.
diPhantxm: I got your idea. I'll do it and ping you when it's ready for review
diPhantxm: @gavv I think it's ready for review.
I made a struct `CallerInfo` that stores function name, file and line, and then slice of these objects is formatted in formatter.
I made such format `at [function]([file]:[line])`. Maybe that was a bad decision, I found such format on google. Maybe I should have kept default Golang format.
gavv: Thanks, will look in upcoming days! BTW I don't remember if I mentioned - welcome to [discord chat](https://discord.gg/5SCPCuCWA9) if you like that format. 

Patch:
diff --git a/README.md b/README.md
index 5a62436..6a9971e 100644
--- a/README.md
+++ b/README.md
@@ -48,7 +48,7 @@ Workflow:
 * Failures are reported using [`testify`](https://github.com/stretchr/testify/) (`assert` or `require` package) or standard `testing` package.
 * JSON values are pretty-printed using `encoding/json`, Go values are pretty-printed using [`litter`](https://github.com/sanity-io/litter).
 * Dumping requests and responses in various formats, using [`httputil`](https://golang.org/pkg/net/http/httputil/), [`http2curl`](https://github.com/moul/http2curl), or simple compact logger.
-* Color support using [`fatih/color`](github.com/fatih/color).
+* Color support using [`fatih/color`](https://github.com/fatih/color).
 
 ##### Tuning
 
diff --git a/assertion.go b/assertion.go
index a66a007..4ce0b3f 100644
--- a/assertion.go
+++ b/assertion.go
@@ -192,6 +192,9 @@ type AssertionFailure struct {
 
 	// Allowed delta between actual and expected
 	Delta *AssertionValue
+
+	// Stacktrace of a fail
+	Stacktrace []CallerInfo
 }
 
 // AssertionValue holds expected or actual value
diff --git a/chain.go b/chain.go
index cee3fcf..d800713 100644
--- a/chain.go
+++ b/chain.go
@@ -2,6 +2,7 @@ package httpexpect
 
 import (
 	"fmt"
+	"runtime"
 	"sync"
 	"testing"
 
@@ -449,6 +450,9 @@ func (c *chain) fail(failure AssertionFailure) {
 	if c.severity == SeverityError {
 		failure.IsFatal = true
 	}
+
+	failure.Stacktrace = GetCallerInfo()
+
 	c.failure = &failure
 }
 
@@ -516,3 +520,41 @@ func isTestingTB(in AssertionHandler) bool {
 	}
 	return false
 }
+
+type CallerInfo struct {
+	FuncName string
+	File     string
+	Line     int
+}
+
+func GetCallerInfo() []CallerInfo {
+	callers := []CallerInfo{}
+	for i := 0; ; i++ {
+		pc, file, line, ok := runtime.Caller(i)
+		if !ok {
+			break
+		}
+
+		if file == "<autogenerated>" {
+			break
+		}
+
+		f := runtime.FuncForPC(pc)
+		if f == nil {
+			break
+		}
+		funcName := f.Name()
+
+		if funcName == "testing.tRunner" {
+			break
+		}
+
+		callers = append(callers, CallerInfo{
+			FuncName: funcName,
+			File:     file,
+			Line:     line,
+		})
+	}
+
+	return callers
+}
diff --git a/formatter.go b/formatter.go
index f0f3729..3bd9920 100644
--- a/formatter.go
+++ b/formatter.go
@@ -59,6 +59,9 @@ type DefaultFormatter struct {
 	// Exclude HTTP response from failure report.
 	DisableResponses bool
 
+	// Enables printing of stacktrace on failure
+	StacktraceMode StacktraceMode
+
 	// Thousand separator.
 	// Default is DigitSeparatorUnderscore.
 	DigitSeparator DigitSeparator
@@ -113,6 +116,16 @@ func (f *DefaultFormatter) FormatFailure(
 	}
 }
 
+type StacktraceMode int
+
+const (
+	// Unconditionally disable stacktrace.
+	StacktraceModeDisabled StacktraceMode = iota
+
+	// Format caller info as `at [function name]([file]:[line])`
+	StacktraceModeDefault
+)
+
 // DigitSeparator defines the separator used to format integers and floats.
 type DigitSeparator int
 
@@ -210,6 +223,9 @@ type FormatData struct {
 	HaveResponse bool
 	Response     string
 
+	HaveStacktrace bool
+	Stacktrace     []string
+
 	EnableColors bool
 	LineWidth    int
 }
@@ -285,6 +301,7 @@ func (f *DefaultFormatter) buildFormatData(
 
 		f.fillRequest(&data, ctx, failure)
 		f.fillResponse(&data, ctx, failure)
+		f.fillStacktrace(&data, ctx, failure)
 	}
 
 	return &data
@@ -547,6 +564,23 @@ func (f *DefaultFormatter) fillResponse(
 	}
 }
 
+func (f *DefaultFormatter) fillStacktrace(
+	data *FormatData, ctx *AssertionContext, failure *AssertionFailure,
+) {
+	data.Stacktrace = []string{}
+
+	if f.StacktraceMode == StacktraceModeDisabled {
+		return
+	}
+	if f.StacktraceMode == StacktraceModeDefault {
+		for _, call := range failure.Stacktrace {
+			formatted := fmt.Sprintf("at %s(%s:%d)", call.FuncName, call.File, call.Line)
+			data.Stacktrace = append(data.Stacktrace, formatted)
+		}
+		data.HaveStacktrace = len(failure.Stacktrace) != 0
+	}
+}
+
 func (f *DefaultFormatter) formatValue(value interface{}) string {
 	if flt := extractFloat32(value); flt != nil {
 		return f.reformatNumber(f.formatFloatValue(*flt, 32))
@@ -1017,6 +1051,13 @@ request: {{ .Request | indent | trim | color $.EnableColors "HiMagenta" }}
 
 response: {{ .Response | indent | trim | color $.EnableColors "HiMagenta" }}
 {{- end -}}
+{{- if .HaveStacktrace }}
+
+trace:
+{{- range $n, $call := .Stacktrace }}
+{{ $call | indent }}
+{{- end -}}
+{{- end -}}
 {{- if .AssertPath }}
 
 assertion:


Test patch:
diff --git a/chain_test.go b/chain_test.go
index a991935..e60a1eb 100644
--- a/chain_test.go
+++ b/chain_test.go
@@ -717,6 +717,22 @@ func TestChain_Severity(t *testing.T) {
 	})
 }
 
+func TestChain_Stacktrace(t *testing.T) {
+	handler := &mockAssertionHandler{}
+
+	chain := newChainWithConfig("test", Config{
+		AssertionHandler: handler,
+	}.withDefaults())
+
+	opChain := chain.enter("test")
+	opChain.fail(testFailure())
+	opChain.leave()
+
+	assert.True(t, opChain.failed())
+	assert.NotNil(t, handler.failure)
+	assert.NotEmpty(t, handler.failure.Stacktrace)
+}
+
 func TestChain_Reporting(t *testing.T) {
 	handler := &mockAssertionHandler{}
 
@@ -751,6 +767,8 @@ func TestChain_Reporting(t *testing.T) {
 	assert.True(t, chain.failed())   // reported to parent
 	assert.NotNil(t, handler.ctx)    // reported to handler
 	assert.NotNil(t, handler.failure)
+
+	failure.Stacktrace = handler.failure.Stacktrace
 	assert.Equal(t, failure, *handler.failure)
 }
 
diff --git a/formatter_test.go b/formatter_test.go
index 02f36d1..04a14a7 100644
--- a/formatter_test.go
+++ b/formatter_test.go
@@ -1056,3 +1056,48 @@ func TestFormatter_ColorMode(t *testing.T) {
 		})
 	}
 }
+
+func TestFormatter_Stacktrace(t *testing.T) {
+	df := &DefaultFormatter{
+		StacktraceMode: StacktraceModeDefault,
+	}
+	ctx := &AssertionContext{}
+
+	cases := []struct {
+		callerInfo CallerInfo
+		want       string
+	}{
+		{
+			CallerInfo{
+				FuncName: "Foo()",
+				File:     "formatter_test.go",
+				Line:     228,
+			},
+			"at Foo()(formatter_test.go:228)",
+		},
+		{
+			CallerInfo{
+				FuncName: "Bar()",
+				File:     "formatter.go",
+				Line:     123,
+			},
+			"at Bar()(formatter.go:123)",
+		},
+		{
+			CallerInfo{
+				FuncName: "Buzz()",
+				File:     "file.go",
+				Line:     5,
+			},
+			"at Buzz()(file.go:5)",
+		},
+	}
+
+	for _, tc := range cases {
+		fl := &AssertionFailure{
+			Stacktrace: []CallerInfo{tc.callerInfo},
+		}
+		fd := df.buildFormatData(ctx, fl)
+		assert.Equal(t, []string{tc.want}, fd.Stacktrace)
+	}
+}