search

powmedia / pow-mongodb-fixtures

Easy JSON fixture loading for MongoDB. Makes managing relationships easier.
MIT License
108 stars 52 forks source link

How to handle multi database access from mocha tests #37

Open BorntraegerMarc opened 7 years ago

BorntraegerMarc commented 7 years ago

So I'm running integration (REST-API) tests with mocha & chai. Every time before the tests start I reset my database & load some sample data in it with pow-mongodb-fixtures. Like this in the beforeEach method:

fixtures.clearAllAndLoad(__dirname + '/../migrations/data', function (err) {
    if (err) {
        console.log(err);
        throw new Error('Database error');
    } else {
        done();
    }
});

I load this fixture in every beforeEach method from every test case.

I got three docker containers: 1) MongoDB container 2) Web-App container 3) Mocha-tests container

I run the tests separately after the mongodb & webapp has started up. But sometimes (every 4th time or so) I get the following error:

komed-test-integration | Uncaught Error: MongoError: cannot perform operation: a background operation is currently running for collection komed-health.users

I guess mocha tries to execute too many db fixtures at once. Does anybody know how I can tell mocha to wait to execute them after the first beforeEach method has finished?

Here is the full stack trace:

PS D:\projects\komed-health> docker-compose -f docker-compose.yml -f docker-compose.test.yml up

Starting komed-mongo
Starting komed-app
Starting komed-test-integration
Attaching to komed-mongo, komed-app, komed-test-integration
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=ede62ff72efe
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] db version v3.2.11
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] git version: 009580ad490190ba33d1c6253ebd8d91808923e4
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1t  3 May 2016
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] allocator: tcmalloc
komed-app                 | npm info it worked if it ends with ok
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] modules: none
komed-app                 | npm info using npm@3.10.9
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten] build environment:
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten]     distmod: debian81
komed-app                 | npm info using node@v6.9.2
komed-mongo               | 2016-12-24T08:22:20.768+0000 I CONTROL  [initandlisten]     distarch: x86_64
komed-mongo               | 2016-12-24T08:22:20.769+0000 I CONTROL  [initandlisten]     target_arch: x86_64
komed-mongo               | 2016-12-24T08:22:20.769+0000 I CONTROL  [initandlisten] options: {}
komed-mongo               | 2016-12-24T08:22:20.772+0000 I -        [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage en
gine to 'wiredTiger'.
komed-mongo               | 2016-12-24T08:22:20.772+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_max=4),config_base=false,st
atistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
komed-mongo               | 2016-12-24T08:22:21.045+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
komed-mongo               | 2016-12-24T08:22:21.045+0000 I NETWORK  [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
komed-mongo               | 2016-12-24T08:22:21.046+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
komed-app                 | npm info lifecycle komed-health@0.0.1~prestart: komed-health@0.0.1
komed-app                 | npm info lifecycle komed-health@0.0.1~start: komed-health@0.0.1
komed-app                 |
komed-app                 | > komed-health@0.0.1 start /home/app
komed-app                 | > node ./app
komed-app                 |
komed-test-integration    | npm info it worked if it ends with ok
komed-test-integration    | npm info using npm@3.10.9
komed-test-integration    | npm info using node@v6.9.2
komed-test-integration    | npm info lifecycle komed-health@0.0.1~pretest-integration: komed-health@0.0.1
komed-test-integration    | npm info lifecycle komed-health@0.0.1~test-integration: komed-health@0.0.1
komed-test-integration    |
komed-test-integration    | > komed-health@0.0.1 test-integration /home/app
komed-test-integration    | > mocha --timeout 10000 --reporter spec --compilers ts:ts-node/register integration-tests/**/*.test.ts
komed-test-integration    |
komed-mongo               | 2016-12-24T08:22:27.685+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.3:34810 #1 (1 connection now open)
komed-mongo               | 2016-12-24T08:22:27.686+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.3:34812 #2 (2 connections now open)
komed-app                 | Redirecting http requests from port 5000 to ssl port 5001
komed-app                 |
komed-test-integration    |
komed-test-integration    |
komed-test-integration    |   Home test
komed-test-integration    | HEYAAA 0
komed-app                 | Release 0.0.1 started under env: dev
komed-app                 | Running under port 5001
komed-app                 |
komed-mongo               | 2016-12-24T08:22:28.169+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.3:34816 #3 (3 connections now open)
komed-mongo               | 2016-12-24T08:22:28.169+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.3:34818 #4 (4 connections now open)
komed-mongo               | 2016-12-24T08:22:28.169+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.3:34820 #5 (5 connections now open)
komed-mongo               | 2016-12-24T08:22:28.170+0000 I INDEX    [conn1] build index on: komed-health.sessions properties: { v: 1, key: { expires: 1 }, name: "expires_1", ns: "komed-health.
sessions", expireAfterSeconds: 0 }
komed-mongo               | 2016-12-24T08:22:28.178+0000 I INDEX    [conn1]      building index using bulk method
komed-mongo               | 2016-12-24T08:22:28.184+0000 I INDEX    [conn1] build index done.  scanned 1 total records. 0 secs
komed-mongo               | 2016-12-24T08:22:28.224+0000 I INDEX    [conn2] build index on: komed-health.messages properties: { v: 1, key: { posted: 1 }, name: "posted_1", ns: "komed-health.me
ssages", background: true }
komed-mongo               | 2016-12-24T08:22:28.224+0000 I INDEX    [conn2] build index done.  scanned 0 total records. 0 secs
komed-app                 | GET / 200 14.134 ms - 2437
komed-test-integration    |     Γ£ô should responds with initial web page
komed-app                 | GET / 200 4.713 ms - 2437
komed-test-integration    |
komed-test-integration    |   i18n test
komed-mongo               | 2016-12-24T08:22:28.287+0000 I INDEX    [conn2] build index on: komed-health.rooms properties: { v: 1, unique: true, key: { slug: 1 }, name: "slug_1", ns: "komed-he
alth.rooms", background: true }
komed-mongo               | 2016-12-24T08:22:28.287+0000 I INDEX    [conn2] build index done.  scanned 0 total records. 0 secs
komed-app                 | GET /app/en-lang.json 200 13.018 ms - 90
komed-test-integration    |     Γ£ô should respond with success when getting app translations (42ms)
komed-mongo               | 2016-12-24T08:22:28.314+0000 I INDEX    [conn2] build index on: komed-health.users properties: { v: 1, unique: true, key: { email: 1 }, name: "email_1", ns: "komed-
health.users", background: true }
komed-mongo               | 2016-12-24T08:22:28.329+0000 I INDEX    [conn4] build index on: komed-health.messages properties: { v: 1, key: { _fts: "text", _ftsx: 1, room: 1, posted: -1, _id: 1
 }, name: "text_text_room_1_posted_-1__id_1", ns: "komed-health.messages", background: true, weights: { text: 1 }, default_language: "english", language_override: "language", textIndexVersion:
 3 }
komed-mongo               | 2016-12-24T08:22:28.329+0000 I INDEX    [conn4] build index done.  scanned 0 total records. 0 secs
komed-mongo               | 2016-12-24T08:22:28.329+0000 I INDEX    [conn2] build index done.  scanned 2 total records. 0 secs
komed-app                 | GET /auth/en-lang.json 200 11.611 ms - 893
komed-test-integration    |     Γ£ô should respond with success when getting auth translations
komed-test-integration    |
komed-test-integration    |   Account test
komed-mongo               | 2016-12-24T08:22:28.348+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37948 #6 (6 connections now open)
komed-mongo               | 2016-12-24T08:22:28.382+0000 I INDEX    [conn2] build index on: komed-health.usermessages properties: { v: 1, key: { posted: 1 }, name: "posted_1", ns: "komed-healt
h.usermessages", expireAfterSeconds: 21600, background: true }
komed-mongo               | 2016-12-24T08:22:28.383+0000 I INDEX    [conn2] build index done.  scanned 0 total records. 0 secs
komed-mongo               | 2016-12-24T08:22:28.396+0000 I COMMAND  [conn6] CMD: drop komed-health.messages
komed-mongo               | 2016-12-24T08:22:28.398+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37950 #7 (7 connections now open)
komed-mongo               | 2016-12-24T08:22:28.399+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37952 #8 (8 connections now open)
komed-mongo               | 2016-12-24T08:22:28.400+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37954 #9 (9 connections now open)
komed-mongo               | 2016-12-24T08:22:28.400+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37956 #10 (10 connections now open)
komed-mongo               | 2016-12-24T08:22:28.402+0000 I INDEX    [conn2] build index on: komed-health.users properties: { v: 1, unique: true, key: { username: 1 }, name: "username_1", ns: "
komed-health.users", background: true }
komed-mongo               | 2016-12-24T08:22:28.427+0000 I COMMAND  [conn6] CMD: drop komed-health.users
komed-mongo               | 2016-12-24T08:22:28.429+0000 I INDEX    [conn2] build index done.  scanned 2 total records. 0 secs
komed-mongo               | 2016-12-24T08:22:28.449+0000 I INDEX    [conn4] build index on: komed-health.usermessages properties: { v: 1, key: { users: 1, posted: -1, _id: 1 }, name: "users_1_
posted_-1__id_1", ns: "komed-health.usermessages", background: true }
komed-mongo               | 2016-12-24T08:22:28.450+0000 I COMMAND  [conn6] CMD: drop komed-health.sessions
komed-mongo               | 2016-12-24T08:22:28.454+0000 I INDEX    [conn4] build index done.  scanned 0 total records. 0 secs
komed-mongo               | 2016-12-24T08:22:28.483+0000 I COMMAND  [conn6] CMD: drop komed-health.rooms
komed-test-integration    |     1) "before each" hook: setup database
komed-test-integration    |
komed-test-integration    |   Account test
komed-mongo               | 2016-12-24T08:22:28.498+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37958 #11 (11 connections now open)
komed-mongo               | 2016-12-24T08:22:28.507+0000 I COMMAND  [conn6] CMD: drop komed-health.usermessages
komed-mongo               | 2016-12-24T08:22:28.512+0000 I COMMAND  [conn11] CMD: drop komed-health.users
komed-mongo               | 2016-12-24T08:22:28.513+0000 I NETWORK  [initandlisten] connection accepted from 172.18.0.4:37960 #12 (12 connections now open)
komed-mongo               | 2016-12-24T08:22:28.550+0000 I COMMAND  [conn11] CMD: drop komed-health.usermessages
komed-test-integration    | { MongoError: ns not found
komed-test-integration    |     at Function.MongoError.create (/home/app/node_modules/mongodb-core/lib/error.js:31:11)
komed-test-integration    |     at /home/app/node_modules/mongodb-core/lib/connection/pool.js:483:72
komed-test-integration    |     at authenticateStragglers (/home/app/node_modules/mongodb-core/lib/connection/pool.js:429:16)
komed-test-integration    |     at Connection.messageHandler (/home/app/node_modules/mongodb-core/lib/connection/pool.js:463:5)
komed-test-integration    |     at Socket.<anonymous> (/home/app/node_modules/mongodb-core/lib/connection/connection.js:317:22)
komed-test-integration    |     at emitOne (events.js:96:13)
komed-test-integration    |     at Socket.emit (events.js:188:7)
komed-test-integration    |     at readableAddChunk (_stream_readable.js:176:18)
komed-test-integration    |     at Socket.Readable.push (_stream_readable.js:134:10)
komed-test-integration    |     at TCP.onread (net.js:548:20)
komed-test-integration    |   name: 'MongoError',
komed-test-integration    |   message: 'ns not found',
komed-test-integration    |   ok: 0,
komed-test-integration    |   errmsg: 'ns not found',
komed-test-integration    |   code: 26 }
komed-test-integration    |     2) "before each" hook: setup database
komed-test-integration    |
komed-test-integration    |
komed-test-integration    |   3 passing (741ms)
komed-test-integration    |   2 failing
komed-test-integration    |
komed-test-integration    |   1) Account test "before each" hook: setup database:
komed-test-integration    |      Uncaught Error: MongoError: cannot perform operation: a background operation is currently running for collection komed-health.users
komed-test-integration    |       at integration-tests/login.test.ts:24:23
komed-test-integration    |       at node_modules/pow-mongodb-fixtures/src/index.js:215:21
komed-test-integration    |       at node_modules/pow-mongodb-fixtures/node_modules/async/lib/async.js:99:21
komed-test-integration    |       at handleCallback (node_modules/mongodb/lib/utils.js:95:56)
komed-test-integration    |       at node_modules/mongodb/lib/db.js:838:20
komed-test-integration    |       at handleCallback (node_modules/mongodb/lib/utils.js:95:56)
komed-test-integration    |       at node_modules/mongodb/lib/db.js:311:20
komed-test-integration    |       at node_modules/mongodb-core/lib/connection/pool.js:455:18
komed-test-integration    |       at _combinedTickCallback (internal/process/next_tick.js:67:7)
komed-test-integration    |       at process._tickCallback (internal/process/next_tick.js:98:9)
komed-test-integration    |
komed-test-integration    |   2) Account test "before each" hook: setup database:
komed-test-integration    |      Uncaught Error: Database error
komed-test-integration    |       at integration-tests/register.test.ts:24:23
komed-test-integration    |       at node_modules/pow-mongodb-fixtures/src/index.js:215:21
komed-test-integration    |       at node_modules/pow-mongodb-fixtures/node_modules/async/lib/async.js:99:21
komed-test-integration    |       at handleCallback (node_modules/mongodb/lib/utils.js:95:56)
komed-test-integration    |       at node_modules/mongodb/lib/db.js:838:20
komed-test-integration    |       at handleCallback (node_modules/mongodb/lib/utils.js:95:56)
komed-test-integration    |       at node_modules/mongodb/lib/db.js:311:20
komed-test-integration    |       at node_modules/mongodb-core/lib/connection/pool.js:455:18
komed-test-integration    |       at _combinedTickCallback (internal/process/next_tick.js:67:7)
komed-test-integration    |       at process._tickCallback (internal/process/next_tick.js:98:9)
komed-test-integration    |
komed-test-integration    |
komed-test-integration    |
komed-mongo               | 2016-12-24T08:22:28.578+0000 I NETWORK  [conn11] end connection 172.18.0.4:37958 (11 connections now open)
komed-mongo               | 2016-12-24T08:22:28.578+0000 I NETWORK  [conn7] end connection 172.18.0.4:37950 (11 connections now open)
komed-mongo               | 2016-12-24T08:22:28.578+0000 I NETWORK  [conn9] end connection 172.18.0.4:37954 (11 connections now open)
komed-mongo               | 2016-12-24T08:22:28.579+0000 I NETWORK  [conn10] end connection 172.18.0.4:37956 (10 connections now open)
komed-mongo               | 2016-12-24T08:22:28.579+0000 I NETWORK  [conn8] end connection 172.18.0.4:37952 (8 connections now open)
komed-mongo               | 2016-12-24T08:22:28.579+0000 I NETWORK  [conn12] end connection 172.18.0.4:37960 (6 connections now open)
komed-mongo               | 2016-12-24T08:22:28.580+0000 I NETWORK  [conn6] end connection 172.18.0.4:37948 (5 connections now open)
komed-test-integration    |
komed-test-integration    | npm info lifecycle komed-health@0.0.1~test-integration: Failed to exec test-integration script
komed-test-integration    | npm ERR! Linux 4.4.39-moby
komed-test-integration    | npm ERR! argv "/usr/local/bin/node" "/usr/local/bin/npm" "run" "test-integration"
komed-test-integration    | npm ERR! node v6.9.2
komed-test-integration    | npm ERR! npm  v3.10.9
komed-test-integration    | npm ERR! code ELIFECYCLE
komed-test-integration    | npm ERR! komed-health@0.0.1 test-integration: `mocha --timeout 10000 --reporter spec --compilers ts:ts-node/register integration-tests/**/*.test.ts`
komed-test-integration    | npm ERR! Exit status 2
komed-test-integration    | npm ERR!
komed-test-integration    | npm ERR! Failed at the komed-health@0.0.1 test-integration script 'mocha --timeout 10000 --reporter spec --compilers ts:ts-node/register integration-tests/**/*.test
.ts'.
komed-test-integration    | npm ERR! Make sure you have the latest version of node.js and npm installed.
komed-test-integration    | npm ERR! If you do, this is most likely a problem with the komed-health package,
komed-test-integration    | npm ERR! not with npm itself.
komed-test-integration    | npm ERR! Tell the author that this fails on your system:
komed-test-integration    | npm ERR!     mocha --timeout 10000 --reporter spec --compilers ts:ts-node/register integration-tests/**/*.test.ts
komed-test-integration    | npm ERR! You can get information on how to open an issue for this project with:
komed-test-integration    | npm ERR!     npm bugs komed-health
komed-test-integration    | npm ERR! Or if that isn't available, you can get their info via:
komed-test-integration    | npm ERR!     npm owner ls komed-health
komed-test-integration    | npm ERR! There is likely additional logging output above.
komed-test-integration    |
komed-test-integration    | npm ERR! Please include the following file with any support request:
komed-test-integration    | npm ERR!     /home/app/npm-debug.log
komed-test-integration exited with code 1
BorntraegerMarc commented 7 years ago

Apparently this PR fixes it: https://github.com/powmedia/pow-mongodb-fixtures/pull/31 but the repo owner isn't around anymore...

I've forked the project and published an own package: https://www.npmjs.com/package/mongodb_fixtures

Feel free to use it 😄