integration_ShowAllNotes test failing randomly

cd CliClient
npm run test -- --filter="integration_ShowAllNotes"

Sometimes all tests pass. But it also sometimes fails with different errors.

This is one type of error I get.
Failures:

  1. integration_ShowAllNotes should show retain note selection when going from a folder to all-notes
    Message:
    Unhandled promise rejection: Error: Accessing database before it has been initialised

Sometimes I also get this failure
Failures:

  1. integration_ShowAllNotes should show all notes
    Message:
    Expected $.length = 0 to equal 9.

Here are the error logs.
https://pastebin.com/wQfpxVDk

can you share the logs via a tool listed in https://www.designbombs.com/code-sharing-websites/ or good old https://pastebin.com/, allowing us to get the complete picture?

https://pastebin.com/wQfpxVDk

1 Like

@naviji how often does it fail roughly?

Is you code on a branch I can try?

At what point on master did you branch? There have been some fixes recently, so I’d like to confirm you have them or not.

The database error appears about 3/5 times.

Is you code on a branch I can try?

It happens on the latest original master branch without any code changes by me. It should be reproducible.

Unhandled promise rejection: Error: Accessing database before it has been initialised

I believe this error is not a fault of the test. It's just that if I run
npm run test -- --filter="integration_ShowAllNotes"
soon enough, the database does not have time to initialize.

But I don't understand how it sometimes fails with this error.

> joplin@1.0.161 test /home/naviji/Projects/RoughWork/joplin/CliClient
> gulp buildTests -L && jasmine --config=tests/support/jasmine.json "--filter=integration_ShowAllNotes"

Testing with sync target: memory
Randomized with seed 44614
Started
.F

Failures:
1) integration_ShowAllNotes should show all notes
  Message:
    Expected $.length = 0 to equal 9.
    Expected $[0] = undefined to equal '185752143570473f9f69fd7b9dad84be'.
    Expected $[1] = undefined to equal '3a8c9f50f6dd438dad75fa242dc30cfe'.
    Expected $[2] = undefined to equal '627fec95b1c14f19a2c71eb2ed59a9ab'.
    Expected $[3] = undefined to equal '710f8ba8f087438784b29559f6cf777f'.
    Expected $[4] = undefined to equal '886fdeffa1144fe49d2f15e82fc41449'.
    Expected $[5] = undefined to equal 'b232d5bbd6934513b8faca72fa4b95c0'.
    Expected $[6] = undefined to equal 'c6c6d738e3b74133ae2244d7c4a3567f'.
    Expected $[7] = undefined to equal 'd84d00d46d9a423b9d8a80d08e62c85b'.
    Expected $[8] = undefined to equal 'eed010a53d5e4e8082c5fb450ee2648a'.

It is most likely due to an error in the test harness, where a process is not being shut down and restarted correctly.

I just ran the test as you describe (latest master) and repeated a few hundred times, and I am not getting any errors.

I will have a closer look.

@mic704b, the tests are ran in random order and you can use the seed, in that case 44614, to run them in a predefined order. I think the command would be npm test -- --seed 44164

Failing tests have not happened in pull requests or CI though, so it could be a problem with naviji’s setup.

Yes, I've tried that too just now, 150 repeats no fails.

I suspect the order doesn't matters here, however I suspect it will always be the second test that fails for him.

There is certainly something about his setup that aggravates the problem.

I actually have some more fixes on another branch. On that branch, I had to stop the synchronizer from running, because when it started a sync in the background during the tests, it would cause the running test to miss it's 100ms deadline and so fail. Perhaps this is related to that?

I could prepare a branch with just the fixes, and perhaps @naviji could try it and see if it stops the problems he's seeing?

Maybe. If it times out it would show a different error, but it might be related in that when something is running slow, some clean up that runs asynchronously doesn't finish on time.

Thanks. I'll try that.

in that case a common dev-plattform could help. The VM is ready but I haven't got the chance yet to run any builds etc.

Yes.

I can see in addition to the synchronizer disable, I also found an bug in the shutdown of the 'registry.js' timers. They are a little more complex than the other services, and I think I got it wrong previously.

@naviji if you would like to try again with the extra test harness fixes, here they are.

This is the patch with the WIP changes:

test-harness-fixes.patch (18.0 KB)

Please apply the patch from your project base directory (git apply test-harness-fixes.patch) and try the tests again. Don’t forget to npm install in the CliClient directory.

FYI the patch was generated from the branch fix/test-harness-fixes at https://github.com/mic704b/joplin.git

No change. Still giving the same errors.
https://pastebin.com/VwZJ7FTx

Based on the error message, a ItemChange.waitForAllSaved() should be added somewhere, probably on teardown.

In beforeEach actually, it’s best to always have:

	beforeEach(async (done) => {
		await setupDatabaseAndSynchronizer(1);
		await switchClient(1);
		done();
	});

event if you do nothing with the synchronizer, as it setups everything and wait for certain things, like the ItemChange model to be ready.

That is interesting. If the integration tests runs first (before any unit tests) I can see a path (bug) where this call doesn't happen. I'll look into it and maybe create another patch for naviji to try.

Hi @naviji, does the failure happen when you run just a single test. Eg

npm run test -- --filter="should show all notes"

If so, could you go to the test-build/profile directory and retrieve the log files. They may contain more info.

Yup. test v3 - Pastebin.com
I didn't apply the patch for this run.

log.txt (483 Bytes) log-database.txt (1.8 KB)