Print in e2e message diff between expected and got message

mszostok commented 1 year ago

Overview

Currently, when e2e test expectation fails, we see in error logs all messages that were posted on a given channel with a message while waiting for condition: last error: message assertion function returned false; fetched messages::

Example logs, click me

``` === RUN TestSlack/Executor/Get_Pods_with_k8s_prefix_kubectl bots_test.go:439: Error Trace: bots_test.go:439 Error: Received unexpected error: while waiting for condition: last error: message assertion function returned false; fetched messages: []slack.Message{ slack.Message{ Msg: slack.Msg{ Type: "message", User: "U03G3MQLFC2", Text: "`kubectl get pods` on `sample`\n```\nNo resources found in default namespace.\n```\n", Timestamp: "1664352221.046189", BotID: "B03GTEUMJQ0", BotProfile: &slack.BotProfile{ AppID: "AF5DZLHPC", Icons: &slack.Icons{ Image36: "https://avatars.slack-edge.com/2019-01-15/523890478611_539be8a0b4811[68](https://github.com/kubeshop/botkube/actions/runs/3141732818/jobs/5104649726#step:7:69)6d310_36.png", Image48: "https://avatars.slack-edge.com/2019-01-15/523890478611_539be8a0b4811686d310_48.png", Image[72](https://github.com/kubeshop/botkube/actions/runs/3141732818/jobs/5104649726#step:7:73): "https://avatars.slack-edge.com/2019-01-15/523890478611_539be8a0b4811686d310_72.png", }, ID: "B03GTEUMJQ0", Name: "BotKube", TeamID: "T03GG4212N5", Updated: 16566822[76](https://github.com/kubeshop/botkube/actions/runs/3141732818/jobs/5104649726#step:7:77), }, Team: "T03GG4212N5", Blocks: slack.Blocks{ BlockSet: []slack.Block{ &slack.RichTextBlock{ Type: "rich_text", BlockID: "HSr", Elements: []slack.RichTextElement{ &slack.RichTextSection{ Type: "rich_text_section", Elements: []slack.RichTextSectionElement{ &slack.RichTextSectionTextElement{ Type: "text", Text: "kubectl get pods", Style: &slack.RichTextSectionTextStyle{ Code: true, }, }, &slack.RichTextSectionTextElement{ Type: "text", Text: " on ", }, &slack.RichTextSectionTextElement{ Type: "text", Text: "sample", Style: &slack.RichTextSectionTextStyle{ Code: true, }, }, }, }, &slack.RichTextUnknown{ Type: "rich_text_preformatted", Raw: "{\"type\":\"rich_text_preformatted\",\"elements\":[{\"type\":\"text\",\"text\":\"No resources found in default namespace.\\n\"}]}", }, }, }, }, }, }, }, } Test: TestSlack/Executor/Get_Pods_with_k8s_prefix_kubectl ```

this is not helpful as we don't see what was expected. Sometimes is just a matter of wrong padding, missing formatting etc. It will be good to see the diff, e.g.:

        --- expected
        +++ actual

        -*Angry? Amazed?*
        +Angry? Amazed?

Acceptance Criteria

See diff between expected and got message in e2e tests
The diff is not printed if the expectation was finally satisfied (e.g. 3rd message matched, don't display diff for first 2 tries). Print only if we have a final error on expectation (all messages were tried and all of them failed)
Try to don't print diff for messages that are different in 100%. Print diff only for "promising candidate messages".
- NOTE: It's a real case when we do match against a slice of recent messages, e.g. we get 3 messages and 2 of them are completely different, and only the 3rd one is the expected one but there is some diff, e.g. wrong padding etc.

Reason

Reduce time spent on debugging failing e2e tests.

wangyangjun commented 1 year ago

I am interested to work on this ticket.

pkosiec commented 1 year ago

Awesome, thank you @wangyangjun! 🚀 Feel free to ping us here or on Slack if you need any help or the scope is not clear.

wangyangjun commented 1 year ago

@mszostok @pkosiec I have a propose of implementing this ticket. Update type MessageAssertion to type MessageAssertion func(content string) (bool, int, string). The new return values are size of total common message(int) and diff(string). The common message is calculated with GetMatchingBlocks -- https://pkg.go.dev/github.com/pmezard/go-difflib/difflib#SequenceMatcher.GetMatchingBlocks The diff string is something similar to this diff -- https://github.com/stretchr/testify/blob/master/assert/assertions.go#L1685

Any suggestion or comment?

pkosiec commented 1 year ago

@wangyangjun Sounds good to me 👍 Thanks for the PR, will review it in a few hours!

wangyangjun commented 1 year ago

@pkosiec Thanks. One point in the description of this ticket is still not clear to me --don't display diff for first 2 tries. Actually I couldn't find 3 times retry logic, there might be something I missed. We could have a slack huddle if you have time.

pkosiec commented 1 year ago

Right, this is something which is satisfied out of the box, as we print just the last error while waiting, and the error is not printed. AFAIR it was written down just to keep the current behavior, which your PR does 👍

kubeshop / botkube