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

Tests sometime log datastore close error but still pass #1349

Closed
AndrewSisley opened this issue Apr 13, 2023 · 1 comment
Closed

Tests sometime log datastore close error but still pass #1349

AndrewSisley opened this issue Apr 13, 2023 · 1 comment
Labels
area/testing Related to any test or testing suite bug Something isn't working

Comments

@AndrewSisley
Copy link
Contributor

AndrewSisley commented Apr 13, 2023

It looks like something is still occasionally trying to access the datastore after the database has been closed. The test still passed in this case, but there is a chance that it may be occasionally responsible for test flakiness. Rate of occurrence seems quite low (<~= 1:100), but I have seen it a few times now.

gotestsum --format testname -- ./tests/integration/subscription -race -shuffle=on
PASS tests/integration/subscription.TestSubscriptionWithUpdateAllMutations (0.21s)
PASS tests/integration/subscription.TestSubscriptionWithFilterAndOneCreateMutation (0.16s)
PASS tests/integration/subscription.TestSubscriptionWithFilterAndCreateMutations (0.12s)
PASS tests/integration/subscription.TestSubscriptionWithCreateMutations (0.13s)
PASS tests/integration/subscription.TestSubscriptionWithUpdateMutations (0.12s)
PASS tests/integration/subscription.TestSubscriptionWithFilterAndOneCreateMutationOutsideFilter (0.11s)
2023-04-13T16:36:42.440Z, ERROR, defra.db, datastore closed
PASS tests/integration/subscription

My best guess so far is that this is being logged in db/subscriptions.go handleSubscription, with an event being received after close:

for evt := range pub.Event() {
		txn, err := db.NewTxn(ctx, false)
		if err != nil {
			log.Error(ctx, err.Error())
			continue
		}

*simpleChannel[T].Close() is asynchronous, and does leave room for it to not have fully closed before the root datastore has closed. It would however be odd that an 'extra' event could be received after the datastore has been closed - this would suggest that the test is exiting prematurely, and that extra, unexpected, events are being received.

@AndrewSisley AndrewSisley added bug Something isn't working area/testing Related to any test or testing suite labels Apr 13, 2023
@AndrewSisley AndrewSisley added this to the DefraDB v0.5.1 milestone Apr 13, 2023
@AndrewSisley
Copy link
Contributor Author

Related to: #1351

AndrewSisley added a commit that referenced this issue Apr 13, 2023
This fixes #1349 where events are attempted to be handled after database close
AndrewSisley added a commit that referenced this issue Apr 13, 2023
This fixes #1349 where events are attempted to be handled after database close
shahzadlone pushed a commit to shahzadlone/defradb that referenced this issue Feb 23, 2024
* Guarantee event processing order

* Make Close synchronous

This fixes sourcenetwork#1349 where events are attempted to be handled after database close
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/testing Related to any test or testing suite bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant