Investigate flakey Couch DB test

[akhenry]

Summary

A test that was recently modified for the Couch DB plugin has started failing randomly. Although it passed automated tests when originally merged, it subsequently failed in master, and then failed in other pull requests after then merged from master. Some investigation is needed to understand why it's failing.

Steps to Reproduce

1. git checkout master
2. Re-enable the flakey test
3. npm run test
4. Observe the test failure
5. If the test does not fail, repeat step 3 until it does.

[akhenry]

@scottbell Do you mind taking a look?

[scottbell]

I'll take a look and see if I can work out what's going on. I was able to replicate it locally before the CouchDB change by checking out a previous commit:
d10561f
and run npm run test:debug until the test fails:

      ✗ updates an object (14ms)
	Error: Expected spy update to have been called.
	    at <Jasmine>
	    at eval (webpack-internal:///./src/plugins/persistence/couch/pluginSpec.js:124:45)

I suspect there's a timing issue going on here, but unclear where.

[scottbell]

I think I found a clue. It seems OpenMCT thinks the object is already persisted between tests, even though we're resetting OpenMCT between tests:

afterEach(async () => {
        await resetApplicationState(openmct);
    });

Perhaps resetApplicationState isn't waiting for all the objects to be cleared before returning...

[scottbell]

One save in OpenMCT kicks off a big chain of saves & mutates:

    at ObjectAPI.save (webpack-internal:///./src/api/objects/ObjectAPI.js:351:21)
    at ObjectAPI.mutate (webpack-internal:///./src/api/objects/ObjectAPI.js:491:14)
    at ObjectAPI.save (webpack-internal:///./src/api/objects/ObjectAPI.js:369:18)
    at ObjectAPI.mutate (webpack-internal:///./src/api/objects/ObjectAPI.js:491:14)
    at ObjectAPI.save (webpack-internal:///./src/api/objects/ObjectAPI.js:361:22)
    at async UserContext.eval (webpack-internal:///./src/plugins/persistence/couch/pluginSpec.js:136:28)

save can call mutate, which in turn calls save, but neither is awaiting the other, so I think this may be the source of the issue. E.g., in mutate:

if (this.isTransactionActive()) {
        this.transaction.add(domainObject);
    } else {
        this.save(domainObject);
    }

and in save:

this.mutate(domainObject, 'persisted', persistedTime);

These save calls ground out into a asynchronous queue in the CouchDB adapter.

[scottbell]

Ok, I think I know what's going on. Per the above 👆 comment, whenever one calls save or update, this actually causes a chain of save & mutate events due to the persistedTime being mutated, which in turns calls another save, etc.:
https://github.com/nasa/openmct/blob/master/src/api/objects/ObjectAPI.js#L352
https://github.com/nasa/openmct/blob/master/src/api/objects/ObjectAPI.js#L362
Depending on how fast the Javascript engine processes everything, the second order save commands to persist the persistedTime (woof, very meta), can cause the hasAlreadyBeenPersisted to return true:
https://github.com/nasa/openmct/blob/master/src/api/objects/ObjectAPI.js#L669
as persistedTime is now greater than the original modifiedTime passed by the original save call:
https://github.com/nasa/openmct/blob/master/src/plugins/persistence/couch/pluginSpec.js#L116
OpenMCT now thinks the Object has already been persisted, and thus the original save returns without calling the provider.update function.
A quick and dirty fix just for the test is to set this modified time well in the future, e.g.:

mockDomainObject.modified = Date.now() + 1000;

But I'm wondering if we've discovered a bug. Namely, are we doing the right thing with persistedTime? Shouldn't this be an atomic transaction? Or maybe just something the provider handles so the subsequent save/mutate cycles doesn't start?

What do you think @akhenry?

[scottbell]

@akhenry If we're happy with the dirty fix, I have a PR for it here:
#4473

[scottbell]

@shefalijoshi this can be closed per our discussion.

[shefalijoshi]

Closing.