Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

e2e: Log errors #1683

Merged
merged 1 commit into from
Dec 4, 2024
Merged

e2e: Log errors #1683

merged 1 commit into from
Dec 4, 2024

Conversation

nirs
Copy link
Member

@nirs nirs commented Nov 27, 2024

This is an alternative to #1596, trying to keep the test code more
idiomatic, cleaner, and easier to use correctly.

Add e2e/test.T type, embedding the standard library *testing.T, and
keeping a logger. This type overrides testing.T methods logging to the
standard library logger with methods logging to the specific logger.
The Fatal[f] and Error[]f methods log an ERROR messages to make errors
easy to find.

To use the our T type, a test need to wrap the standard library
*testing.T with the per-test logger:

func TestFoo(dt *testing.T) {
    t := e2etesting.WithLog(dt, ctx.Logger())

Now we can use t transparently in this test:

t.Log("This logs an INFO message to our logger")

Note that the wrapped Error() and Fatal() method accept an error and
will log a stracktrace:

if err := ...; err != nil {
    // Log an error with a stracktrace and mark the test as failed.
    t.Error(err, "Failed, trying next step")
}

if err := ...; err != nil {
    // Log an error with a stracktrace and fail the test immediately.
    t.Fatal(err, "Failed, cannot continue")
}

Example error log (wrapped for readability):

2024-11-29T03:12:32.837+0200	ERROR	subscr-deploy-rbd-busybox    test/testing.go:55
    Failed to failover workload: fake error in waitAndUpdateDRPC: failover to cluster "dr1"
github.com/ramendr/ramen/e2e/test.(*T).Fatalf
        /Users/nsoffer/src/ramen/e2e/test/testing.go:55
github.com/ramendr/ramen/e2e/test.(*Context).Failover
        /Users/nsoffer/src/ramen/e2e/test/context.go:102
testing.tRunner
        /opt/homebrew/Cellar/go/1.23.3/libexec/src/testing/testing.go:1690

Notes:

  • All the test functions were updated to accept a *testing.T and wrap
    it with per-test log. Test helper functions accept now a *e2e/test.T
    so they don't need extra wrapping.

  • Sub tests requires wrapping the standard library t again, since
    testing.T is a type, not an interface. This adds one line of
    boilerplate for every sub test.

  • All Error[f] and Fatal[f] calls changed to format an error message
    with the underlying error so we should get more helpful error messages
    when something fails deep in the utility functions.

  • When DR sub test (e.g. Deploy) fails, we already logged the error by
    failing the sub test, so we call FailNow() in the parent test to abort
    the parent test silently.

Issues:

  • The stracktrace does not include all callers leading the point the
    error was created, since fmt.Errorf() does not capture the stack. We
    can get better stacktrace by using another error package that does
    this like https://pkg.go.dev/github.com/go-errors/errors.

  • We need to disable the thelper linter in test.Context to allow using
    dt *testing.T and keep the test code idiomatic. Another way is to
    keep t *testing.T, and use et for the wrapped t. This makes the
    test code less idiomatic but it may be more clear that this is a non
    standard t.

Fixes: #1595

Based on #1598 since we need to log on the right logger.

@nirs

This comment was marked as outdated.

@nirs nirs force-pushed the e2e-testing branch 3 times, most recently from ea4e383 to 3f0f6d9 Compare November 27, 2024 16:10
@nirs

This comment was marked as outdated.

@nirs

This comment was marked as outdated.

e2e/test/testing.go Outdated Show resolved Hide resolved
e2e/test/context.go Outdated Show resolved Hide resolved
This is an alternative to RamenDR#1596, trying to keep the test code more
idiomatic, cleaner, and easier to use correctly.

Add e2e/test.T type, embedding the standard library *testing.T, and
keeping a logger. This type overrides testing.T methods logging to the
standard library logger with methods logging to the specific logger.
The Fatal[f] and Error[]f methods log an ERROR messages to make errors
easy to find.

To use the our T type, a test need to wrap the standard library
*testing.T with the per-test logger:

    func TestFoo(dt *testing.T) {
        t := e2etesting.WithLog(dt, ctx.Logger())

Now we can use t transparently in this test:

    t.Log("This logs an INFO message to our logger")

Note that the wrapped Error() and Fatal() method accept an error and
will log a stracktrace:

    if err := ...; err != nil {
        // Log an error with a stracktrace and mark the test as failed.
        t.Error(err, "Failed, trying next step")
    }

    if err := ...; err != nil {
        // Log an error with a stracktrace and fail the test immediately.
        t.Fatal(err, "Failed, cannot continue")
    }

Example error log (wrapped for readability):

    2024-11-29T03:12:32.837+0200	ERROR	subscr-deploy-rbd-busybox    test/testing.go:55
        Failed to failover workload: fake error in waitAndUpdateDRPC: failover to cluster "dr1"
    github.com/ramendr/ramen/e2e/test.(*T).Fatalf
            /Users/nsoffer/src/ramen/e2e/test/testing.go:55
    github.com/ramendr/ramen/e2e/test.(*Context).Failover
            /Users/nsoffer/src/ramen/e2e/test/context.go:102
    testing.tRunner
            /opt/homebrew/Cellar/go/1.23.3/libexec/src/testing/testing.go:1690

Notes:

- All the test functions were updated to accept a `*testing.T` and wrap
  it with per-test log. Test helper functions accept now a `*e2e/test.T`
  so they don't need extra wrapping.

- Sub tests requires wrapping the standard library t again, since
  testing.T is a type, not an interface. This adds one line of
  boilerplate for every sub test.

- All Error[f] and Fatal[f] calls changed to format an error message
  with the underlying error so we should get more helpful error messages
  when something fails deep in the utility functions.

- When DR sub test (e.g. Deploy) fails, we already logged the error by
  failing the sub test, so we call FailNow() in the parent test to abort
  the parent test silently.

Issues:

- The stracktrace does not include all callers leading the point the
  error was created, since fmt.Errorf() does not capture the stack. We
  can get better stacktrace by using another error package that does
  this like https://pkg.go.dev/github.com/go-errors/errors.

- We need to disable the `thelper` linter in test.Context to allow using
  `dt *testing.T` and keep the test code idiomatic. Another way is to
  keep `t *testing.T`, and use `et` for the wrapped t. This makes the
  test code less idiomatic but it may be more clear that this is a non
  standard `t`.

Fixes: RamenDR#1595
Signed-off-by: Nir Soffer <[email protected]>
@nirs nirs marked this pull request as ready for review December 4, 2024 15:05
@raghavendra-talur raghavendra-talur merged commit f730837 into RamenDR:main Dec 4, 2024
22 of 23 checks passed
@nirs nirs deleted the e2e-testing branch December 4, 2024 16:37
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

e2e logging: Hard to find errors in test log
2 participants