testify icon indicating copy to clipboard operation
testify copied to clipboard

assert/require.Len doesn't print anything if the slice is too long

Open fgimian opened this issue 1 year ago • 19 comments

Hey there, I encountered this when attempting to use require.Len as shown below.

package tester_test

import (
	"testing"

	"github.com/stretchr/testify/require"
)

func TestVeryLongSlice(t *testing.T) {
	var bigSlice []string
	for i := 0; i < 20000; i++ {
		bigSlice = append(bigSlice, "hello")
	}

	require.Len(t, bigSlice, 10)
}

Output of test:

=== RUN   TestVeryLongSlice
    tester_test.go:15:
                Error Trace:    C:/Users/Fots/source/tester/tester/tester_test.go:15
                Error:
                Test:           TestVeryLongSlice
--- FAIL: TestVeryLongSlice (0.00s)
FAIL
FAIL    github.com/fgimian/tester/tester        0.150s
FAIL

I haven't quite figured out why this happens, although I can imagine the output would be impractically long anyway. Worst of all, the main assertion message is not displayed which is quite confusing (especially to someone new using the library, like me 😄).

Personally, I think that it would be best not to display the slice at all for the Len function, and instead just display:

Should have X item(s), but has Y

However, I suspect my view on that may not be what some people want. The reason I think it is unwise to print the slice in any form, is that typically when many people are testing for the length of a slice, they may be comparing to a relatively large slice of items (e.g. the output of a mocked API call or similar).

An additional point that I believe has been discussed before is the inconsistency with argument ordering for the Len function which takes the actual first and expected second.

Cheers Fotis

fgimian avatar Jan 23 '24 09:01 fgimian

The easiest workaround for now seems to be:

package tester_test

import (
	"testing"

	"github.com/stretchr/testify/require"
)

func TestVeryLongSlice(t *testing.T) {
	var bigSlice []string
	for i := 0; i < 20000; i++ {
		bigSlice = append(bigSlice, "hello")
	}

	expected := 10
	require.Len(
		t,
		bigSlice,
		expected,
		"Should have %d item(s), but has %d",
		expected,
		len(bigSlice),
	)
}

fgimian avatar Jan 23 '24 09:01 fgimian

We use a scanner to get the text which should go there line by line (it can be multiline) to indent each line until after the field name: https://github.com/stretchr/testify/blob/7caada5a3bc870e8d8e0a31bd9e03b8c3b130f05/assert/assertions.go#L304-L313

This mishandles the scanner.Scan() call. If scanner.Scan() returns false then you need to check scanner.Err() in case it isn't io.EOF. If we did that we'd have found it is bufio.Scanner: token too long.

We need to think of a thing to do about very long lines in this code. We should also probably not produce such a long line from assert.Len, maybe we should truncate after a sane number of elements?

brackendawson avatar Feb 21 '24 13:02 brackendawson

We use a scanner to get the text which should go there line by line (it can be multiline) to indent each line until after the field name:

https://github.com/stretchr/testify/blob/7caada5a3bc870e8d8e0a31bd9e03b8c3b130f05/assert/assertions.go#L304-L313

This mishandles the scanner.Scan() call. If scanner.Scan() returns false then you need to check scanner.Err() in case it isn't io.EOF. If we did that we'd have found it is bufio.Scanner: token too long.

We need to think of a thing to do about very long lines in this code. We should also probably not produce such a long line from assert.Len, maybe we should truncate after a sane number of elements?

That sounds good to me. Personally I'd even be happy for the contents of the slice not to be printed at all, but I suppose this output can be useful for shorter slices when troubleshooting why a test is failing.

Cheers Fotis

fgimian avatar Feb 21 '24 23:02 fgimian

Hello For the argument ordering, you can enable https://github.com/Antonboom/testifylint via golangci

hendrywiranto avatar Feb 22 '24 01:02 hendrywiranto

Hello For the argument ordering, you can enable https://github.com/Antonboom/testifylint via golangci

Thanks, yep I'm using this already, but I think my point was more around the inconsistency of the API and how that particular function feels odd in the context of the rest.

Of course I appreciate that this would be a breaking change but just thought I'd bring it up for consideration in case a major new version of testify was being planned.

Cheers Fotis

fgimian avatar Feb 22 '24 23:02 fgimian

The argument order is covered by #146. Let's keep this issue about the missing message.

brackendawson avatar Feb 23 '24 12:02 brackendawson

This mishandles the scanner.Scan() call. If scanner.Scan() returns false then you need to check scanner.Err() in case it isn't io.EOF. If we did that we'd have found it is bufio.Scanner: token too long.

I've raised a PR that will make sure that the TokenTooLong never happens.

We should also probably not produce such a long line from assert.Len, maybe we should truncate after a sane number of elements?

Agreed. But regardless of the call we take about displaying long messages, I think this fix will be useful.

arjunmahishi avatar Mar 03 '24 11:03 arjunmahishi

I hit this recently and debugged it to the same root cause. For example the following test:

func TestContainsLonglineRepro(t *testing.T) {
	for _, numEntries := range []int{100, 10000} {
		t.Run(fmt.Sprintf("numEntries=%d", numEntries), func(t *testing.T) {
			m := map[string]string{}
			for i := 0; i < numEntries; i++ {
				m[fmt.Sprintf("key%d", i)] = fmt.Sprintf("value%d", i)
			}
			require.Contains(t, m, "not-here")
		})
	}
}

Produces:

--- FAIL: TestContainsLonglineRepro (0.02s)
    --- FAIL: TestContainsLonglineRepro/numEntries=100 (0.00s)
        main_test.go:17:
                Error Trace:    /home/mike/testify-tests/main_test.go:17
                Error:          map[string]string{"key0":"value0", "key1":"value1", "key10":"value10", "key11":"value11", "key12":"value12", "key13":"value13", "key14":"value14", "key15":"value15", "key16":"value16", "key17":"value17", "key18":"value18", "key19":"value19", "key2":"value2", "key20":"value20", "key21":"value21", "key22":"value22", "key23":"value23", "key24":"value24", "key25":"value25", "key26":"value26", "key27":"value27", "key28":"value28", "key29":"value29", "key3":"value3", "key30":"value30", "key31":"value31", "key32":"value32", "key33":"value33", "key34":"value34", "key35":"value35", "key36":"value36", "key37":"value37", "key38":"value38", "key39":"value39", "key4":"value4", "key40":"value40", "key41":"value41", "key42":"value42", "key43":"value43", "key44":"value44", "key45":"value45", "key46":"value46", "key47":"value47", "key48":"value48", "key49":"value49", "key5":"value5", "key50":"value50", "key51":"value51", "key52":"value52", "key53":"value53", "key54":"value54", "key55":"value55", "key56":"value56", "key57":"value57", "key58":"value58", "key59":"value59", "key6":"value6", "key60":"value60", "key61":"value61", "key62":"value62", "key63":"value63", "key64":"value64", "key65":"value65", "key66":"value66", "key67":"value67", "key68":"value68", "key69":"value69", "key7":"value7", "key70":"value70", "key71":"value71", "key72":"value72", "key73":"value73", "key74":"value74", "key75":"value75", "key76":"value76", "key77":"value77", "key78":"value78", "key79":"value79", "key8":"value8", "key80":"value80", "key81":"value81", "key82":"value82", "key83":"value83", "key84":"value84", "key85":"value85", "key86":"value86", "key87":"value87", "key88":"value88", "key89":"value89", "key9":"value9", "key90":"value90", "key91":"value91", "key92":"value92", "key93":"value93", "key94":"value94", "key95":"value95", "key96":"value96", "key97":"value97", "key98":"value98", "key99":"value99"} does not contain "not-here"
                Test:           TestContainsLonglineRepro/numEntries=100
    --- FAIL: TestContainsLonglineRepro/numEntries=10000 (0.02s)
        main_test.go:17:
                Error Trace:    /home/mike/testify-tests/main_test.go:17
                Error:
                Test:           TestContainsLonglineRepro/numEntries=10000
FAIL
FAIL    testify-tests   0.025s

I think the idea of truncating the error after a certain length (1k?, 4k?) seems reasonable, and avoids spamming a huge amount of unnecessary output while making sure that the error message is useful.

Looking at the usage code it might be a bit awkward to do this though (https://github.com/stretchr/testify/blob/master/assert/assertions.go#L938). I guess everywhere messages are formatted would need to be modified with a call to a function that would format and then truncate.

I'd be happy to put together a PR if there is agreement on the right approach.

mrob95 avatar Jul 06 '24 16:07 mrob95

Personally, I think that it would be best not to display the slice at all for the Len function, and instead just display:\n\nShould have X item(s), but has Y\nHowever, I suspect my view on that may not be what some people want. The reason I think it is unwise to print the slice in any form, is that typically when many people are testing for the length of a slice, they may be comparing to a relatively large slice of items (e.g. the output of a mocked API call or similar).

I totally agree with you

ccoVeille avatar Jul 11 '24 19:07 ccoVeille

One naive solution could be to check the length of the sprinted value, and truncate it after let's say an arbitrary value of 20-30 characters. Something with a trailing … plus tge number of items.

If the slice is short and simple, such as a slice 2-3 int/string/bool, the message displayed will be the same as now. The error message will be meaningful.

In other cases, where the message is currently useless, it would be better than nothing.

Any thoughts guys?

ccoVeille avatar Jul 11 '24 20:07 ccoVeille

One naive solution could be to check the length of the sprinted value, and truncate it after let's say an arbitrary value of 20-30 characters. Something with a trailing … plus tge number of items.

If the slice is short and simple, such as a slice 2-3 int/string/bool, the message displayed will be the same as now. The error message will be meaningful.

In other cases, where the message is currently useless, it would be better than nothing.

Any thoughts guys?

A very rough draft, but potentially something like:

func Contains(t TestingT, s, contains interface{}, msgAndArgs ...interface{}) bool {
	if h, ok := t.(tHelper); ok {
		h.Helper()
	}

	ok, found := containsElement(s, contains)
	if !ok {
		return Fail(t, fmt.Sprintf("%#v could not be applied builtin len()", s), msgAndArgs...)
	}
	if !found {
		return Fail(t, fmt.Sprintf("%#v does not contain %#v", s, contains), msgAndArgs...)
	}
	return true
}

Replaced with

func truncatingSprintf(format string, a ...any) string {
	if !strings.HasPrefix(format, "%#v") {
		panic("TruncatingSprintf format argument must begin with '%#v'")
	}
	result := fmt.Sprintf(format, a...)
	if len(result) < 1024 {
		return result
	}
	truncatedFormat := "object of type %T" + format[3:]
	return fmt.Sprintf(truncatedFormat, len(result))
}

func Contains(t TestingT, s, contains interface{}, msgAndArgs ...interface{}) bool {
	if h, ok := t.(tHelper); ok {
		h.Helper()
	}

	ok, found := containsElement(s, contains)
	if !ok {
		return Fail(t, truncatingSprintf("%#v could not be applied builtin len()", s), msgAndArgs...)
	}
	if !found {
		return Fail(t, truncatingSprintf("%#v does not contain %#v", s, contains), msgAndArgs...)
	}
	return true
}

mrob95 avatar Jul 11 '24 20:07 mrob95

Except we were talking about "Len", and not "Contains", yes it's exactly what I'm thinking about

Should I assume there is the same issue (dumping a slice) with Contains?

ccoVeille avatar Jul 11 '24 20:07 ccoVeille

Except we were talking about "Len", and not "Contains", yes it's exactly what I'm thinking about

Should I assume there is the same issue (dumping a slice) with Contains?

Ah yes, I guess there is the same issue for any function which operates on containers (at least Len and Contains, but perhaps others?)

mrob95 avatar Jul 11 '24 20:07 mrob95

1024 seems a very high value.

It's OK for the example reported here, but having 1024 characters dumped on screen, which means 13 screens of text (assuming 80x25 terminal)

maybe 1024 is fine, but then we could simply add an "\n" in the formatted string. This way the message Len expected actual would be visible

ccoVeille avatar Jul 11 '24 20:07 ccoVeille

Let's wait for other people feedbacks. But, yes anything like that would be better than current messages

ccoVeille avatar Jul 11 '24 20:07 ccoVeille

In other code I have written is was presented a little differently:

return fmt.Errorf("wrong result length: wanted %d, got %d: %s>", want, got, f.snippet(v))

Where snippet() was:

// snippet produces a short snippet string of an arbitrary value.                                                                                                                
func (f Formatter) snippet(v any) string {
    const snipLen = 16

    snip := fmt.Sprintf("%#v", v)
    if len(snip) > snipLen {
        // TODO: maybe add a "... %d more"
        snip = snip[:snipLen]
    }   
    return snip
}

They key parts being:

  1. The snippet goes LAST, not first.
  2. The error condition goes FIRST, not last
  3. The snippet is very small - 16 chars, or 32, but not 1024.
  4. You can call snippet() on anything and get an abbreviated snippet.

thockin avatar Jul 11 '24 22:07 thockin

I'm unsure there will be an agreement or consensus on inverting the message and the truncated string. But even if not inverted, I'm OK with it as long we keep the truncated string short so <= 32

ccoVeille avatar Jul 13 '24 15:07 ccoVeille