Refactor error handling to improve test failure logging

[ningziwen]

In many places throughout the test suite, we make use of helper functions (such as containerShouldNotExist used by compose down) to encapsulate assertions. This approach makes the tests more readable and modular, but it also results in less informative logs when a test fails. In particular, the logged error only indicates the line number where the gomega.Expect function is called within the helper function, rather than the line in the main ginkgo.It block that actually triggered the test failure.

For instance, consider the following code:

ginkgo.It(fmt.Sprintf("should stop compose services and delete volumes by specifying %s flag", volumes), func() {
        volumes := volumes
        output := command.StdoutStr(o, "compose", "down", volumes, "--file", composeFilePath)
        containerShouldNotExist(o, containerNames...)
        if !isVolumeInUse(output) {
	        volumeShouldNotExist(o, "compose_data_volume")
        }
})

func containerShouldNotExist(o *option.Option, containerNames ...string) {
        for _, containerName := range containerNames {
                gomega.Expect(command.Stdout(o, "ps", "-a", "-q", "--filter",
	                fmt.Sprintf("name=%s", containerName))).To(gomega.BeEmpty())
        }
}

If a test failure occurs because a container unexpectedly exists, the logged error will indicate the line in containerShouldNotExist where gomega.Expect was called. It won’t, however, reveal which line in the ginkgo.It block is responsible for the failure.

Example log

• [FAILED] [4.510 seconds]
Finch Container Development E2E Tests Compose down command [It] should stop compose services and delete volumes by specifying -v flag
/Users/ec2-user/go/pkg/mod/github.com/runfinch/common-tests@v0.7.0/tests/compose_down.go:45

  [FAILED] Expected
      <[]uint8 | len:13, cap:13>: [51, 55, 54, 49, 50, 100, 48, 48, 100, 48, 97, 53, 10]
  to be empty
  In [It] at: /Users/ec2-user/go/pkg/mod/github.com/runfinch/common-tests@v0.7.0/tests/tests.go:137 @ 06/23/23 09:24:20.648

Proposal

I propose refactoring these helper functions to return an error that includes context about what went wrong, instead of calling gomega.Expect within them. The test case itself can them handle the error and fail if necessary.

Here is the example revised code.

ginkgo.It(fmt.Sprintf("should stop compose services and delete volumes by specifying %s flag", volumes), func() {
        volumes := volumes
        output := command.StdoutStr(o, "compose", "down", volumes, "--file", composeFilePath)
        err := containerShouldNotExist(o, containerNames...)
        gomega.Expect(err).NotTo(gomega.HaveOccurred())
        if !isVolumeInUse(output) {
	        volumeShouldNotExist(o, "compose_data_volume")
        }
})

func containerShouldNotExist(o *option.Option, containerNames ...string) error {
	for _, containerName := range containerNames {
		containerExists := command.Stdout(o, "ps", "-a", "-q", "--filter",
			fmt.Sprintf("name=%s", containerName))
		if containerExists != nil && len(containerExists) > 0 {
			return fmt.Errorf("containerd '%s' exists but should not", containerName)
		}
	}
	return nil
}

The logs will be like this with the change:

• [FAILED] [4.854 seconds]
Finch Shared E2E Tests Compose down command [It] should stop compose services and delete volumes by specifying -v flag
/Users/ningziwe/common-tests/tests/compose_down.go:46

  [FAILED] Unexpected error:
      <*errors.errorString | 0x1400050e350>: 
      containerd 'container1_compose_down' exists but should not
      {
          s: "containerd 'container1_compose_down' exists but should not",
      }
  occurred
  In [It] at: /Users/ningziwe/common-tests/tests/compose_down.go:50 @ 06/23/23 15:03:16.459