Inserts executing after transaction.commit in Knex.js

Question

I want to execute inserts in parallel in a transaction before finishing the transaction. I used Promise.all() and bluebird promises to cancel all the promises if one failed. The problem is that the promises seem to end before the inserts are actually executed. I am using Knex.js. I have 2 promises, one that inserts the username and the email of a user in the users table, and one that encrypts the user password and inserts the email and the encrypted password in the login table.

I have found the order in which the promises and inserts were executed. They execute in this manner. (promise that inserts username and email gets resolved) -> (Knex debugger says that an insert command for username and email was run) -> (promise than inserts email and password gets resolved) -> (transaction.commit) -> (Knex debugger says that an insert command for email and password was run, but the transaction is already over and an error is thrown). Here the problem is clearly that the email and password promise gets executed before the insert for email and password gets executed.

const addUser = (username, email, password) => {
    return db.transaction(trx => {
        let addLoginEntry = Promise.resolve(bcrypt.hash(password, 10)
            .then(secret => {
                trx("login").insert({
                    email: email,
                    secret: secret
                }).then(console.log("PASSWORD INSERTED"));
            })
        );

        let addUserEntry = Promise.resolve(
            trx("users").insert({
                username: username,
                email: email
            })
            .then(console.log("USER INFO INSERTED"))
        )

        Promise.all([
            addLoginEntry,
            addUserEntry
        ])
        .then(args => {
            console.log("All promises done");
            trx.commit(args);
        })
        .catch(error => {
            [addLoginEntry, addUserEntry].forEach(promise =>promise.cancel());
            console.log(error);
            trx.rollback();
        });
    });
}

I expected both the login table and the users table to be updated, but since the transaction commit happened before the login update was added to the transaction, only the users table was updated. Here are the error messages I got with running the program with debugging=true in Knex:

USER INFO INSERTED
{ method: 'insert',
  options: {},
  timeout: false,
  cancelOnTimeout: false,
  bindings: [ 'testemail@test.com', 'test' ],
  __knexQueryUid: '2b1d59b1-1246-4237-87f1-d3fbfff7ba80',
  sql: 'insert into "users" ("email", "username") values (?, ?)',
  returning: undefined }
PASSWORD INSERTED
All promises done
{ method: 'insert',
  options: {},
  timeout: false,
  cancelOnTimeout: false,
  bindings:
   [ 'testemail@test.com',
     '$2b$10$D.qlOo7aDv4WCzssXGXuQeXQ3lZwWZ1.b1CRIn4DuSD.6ov.jzhBm' ],
  __knexQueryUid: 'e3afdc4a-53bd-4f0d-ad71-7aab0d92d014',
  sql: 'insert into "login" ("email", "secret") values (?, ?)',
  returning: undefined }
Unhandled rejection Error: Transaction query already complete, run with DEBUG=knex:tx for more info
    at completedError (C:\PATH_TO\node_modules\knex\src\transaction.js:338:9)
    at C:\PATH_TO\node_modules\knex\src\transaction.js:304:24
    at Promise.cancellationExecute [as _execute] (C:\PATH_TO\node_modules\bluebird\js\release\debuggability.js:335:9)
    at Promise._resolveFromExecutor (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:488:18)
    at new Promise (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:79:10)
    at Client_PG.trxClient.query (C:\PATH_TO\node_modules\knex\src\transaction.js:300:12)
    at Runner.query (C:\PATH_TO\node_modules\knex\src\runner.js:136:36)
    at C:\PATH_TO\node_modules\knex\src\runner.js:40:23
    at tryCatcher (C:\PATH_TO\node_modules\bluebird\js\release\util.js:16:23)
    at C:\PATH_TO\node_modules\bluebird\js\release\using.js:185:26
    at tryCatcher (C:\PATH_TO\node_modules\bluebird\js\release\util.js:16:23)
    at Promise._settlePromiseFromHandler (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:517:31)
    at Promise._settlePromise (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:574:18)
    at Promise._settlePromise0 (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:619:10)
    at Promise._settlePromises (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:699:18)
    at Promise._fulfill (C:\PATH_TO\node_modules\bluebird\js\release\promise.js:643:18)

Answer 1

You are missing one return statement there and your debug printing code has also bugs. I added comments to explain what happens there:

return db.transaction(trx => {
    let addLoginEntry = Promise.resolve(bcrypt.hash(password, 10)
        .then(secret => {
            // ---- MISSING RETURN HERE and PASSWORD INSERTED
            // actually runs before query is even executed.
            // should be .then(() => console.log("PASSWORD INSERTED"))
            // to make that debug print line to be evaluated as part of
            // promise chain
            trx("login").insert({
                email: email,
                secret: secret
            }).then(console.log("PASSWORD INSERTED"));
        })
    );

    // also here USER INFO INSERTED is logged before
    // query is even executed during evaluating query builder
    // method parameters
    let addUserEntry = Promise.resolve(
        trx("users").insert({
            username: username,
            email: email
        })
        .then(console.log("USER INFO INSERTED"))
    )

    // at this point of code USER INFO INSERTED is already printed
    // user add query is ran concurrently with bcrypt call and then 
    // this is resolved and execution continues ....
    Promise.all([
        addLoginEntry,
        addUserEntry
    ])
    .then(args => {
        // .... continues here and concurrently also login insert query is 
        // created and PASSWORD INSERTED log is printed out
        console.log("All promises done");

        // for some reason .commit() gets executed before login insert query is
        // actually triggered. It could have also worked correctly with
        // some luck.
        trx.commit(args);
    })
    .catch(error => {
        [addLoginEntry, addUserEntry].forEach(promise =>promise.cancel());
        console.log(error);
        trx.rollback();
    });
});

So yeah basically there is just one return statement missing.