db.withTransaction using async/await not rolling back

[devlemire]

Summary

From my understanding of the documentation on using db.withTransaction it sounded like any time the promise is rejected, all tx queries would be rolled back. However, I'm seeing my queries persist when the promise does get rejected. I want to believe it's just a lack of understanding on my part.

Example

Code demonstrating the behavior

const startChargeTransaction = async function(db, stripe, meta) {
  let stripeCharge

  try {
    // Create a new stripe charge
    stripeCharge = await stripe.charges.create({
      amount: meta.cost,
      currency: 'usd',
      source: meta.token.id,
      description: meta.description
    })

    await db.withTransaction(async tx => {
      // Store the successful charge in our database
      await tx.payments.store_charge({
        stripe_id: stripeCharge.id,
        amount: meta.cost,
        description: meta.description,
        user_id: meta.user_id,
        sf_id: meta.sf_id
      })

      // Update the user's enrollment to reflect a successful payment
      await tx.query(
        `UPDATE enrollments SET ${meta.column_to_update} = TRUE WHERE user_id = ${
          meta.user_id
        } AND session_id = ${meta.class_session_id}`
      )
    })
  } catch (err) {
    console.error('startChargeTransaction failed in payments_controller.js:', err)
    await stripe.refunds.create({ charge: stripeCharge.id })

    throw new Error(
      'startChargeTransaction failed. However, queries were successfully rolled back and the stripe charge was refunded!'
    )
  }
}

Expected behavior

My update query on table enrollments purposely fails because a table of enrollments does not exist. I would then expect to not see a new record in the charge table when running tx.payments.store_charge.

Actual behavior

My charge table gets populated with a new record even though the transaction throws a rejection.

Additional context

The query for tx.payments.store_charge:

INSERT INTO charge (stripe_id, description, amount, status, "createdAt", "updatedAt", user_id, sf_id)
VALUES (
  ${stripe_id},
  ${description},
  ${amount},
  'paid',
  NOW(),
  NOW(),
  ${user_id},
  ${sf_id}
);

[dmfay]

This is strange. I don't have a ton of time to dig into it at the moment, but I modified the existing tx rollback test to use async and await:

    it('rolls back if anything rejects (async/await)', async function () {
      const total = await db.products.count();

      try {
        await db.withTransaction(async tx => {
          const record = await tx.products.insert({string: 'beta'});

          assert.isOk(record);
          assert.isTrue(record.id > 0);
          assert.equal(record.string, 'beta');

          await tx.products.save({id: 'not an int', description: 'test'});
        });

        assert.fail();
      } catch (err) {
        assert.isOk(err);
        assert.equal(err.code, '22P02');

        const newTotal = await db.products.count();
        assert.equal(total, newTotal);
      }
    });

That catches the error correctly and ensures the transaction rolled back. And it's about the same structure you have: outer async function, try, await db.withTransaction's inner async function, insert a new record, do something wrong and abort.

I suppose it might be possible that some other piece of code is also inserting into store_charge if you're hooking this up as an event? It might be worth logging out the new record id when you insert into store_charge and confirming that it's the same as the one that shouldn't be there afterwards.

[devlemire]

More Context

I'm calling this utility function (startChargeTransaction ) from a method that gets called when hitting /api/payments/class_deposit. The method looks like this:

  pay_class_deposit: async (req, res) => {
    try {
      // Get the db instance from app
      const db = req.app.get('db')
      // Get the stripe instance from app
      const stripe = req.app.get('stripe')
      // Get the user_id of the logged in student
      const { user_id } = req.user
      // Get the required payment information from the request body
      const { token, cost, class_session_id } = req.body
      // Get the most up to date email for the logged in user
      const [{ email }] = await db.get_user({ user_id })
      // Get the user's salesforce id from the enrollments table
      const [{ sf_id }] = await db.get_salesforce_id({
        user_id,
        session_id: class_session_id
      })

      // Format the Stripe charge description
      const description = `Class deposit for ${email}`

      // Call the startChargeTransaction utility function
      await payments_utils.startChargeTransaction(db, stripe, {
        token,
        cost,
        email,
        user_id,
        description,
        column_to_update: 'has_paid_deposit',
        class_session_id,
        sf_id
      })

      res.sendStatus(200)
    } catch (err) {
      console.error('pay_class_deposit method failed in payments_controller.js:', err)
      res.status(500).send(err)
    }
  }

The server logs

student-hub-node-container | The record has the following Stripe ID: ch_1Cmngk228emtMZTzIFD96ADv
student-hub-node-container | The record has the following description: Class deposit for james.lemire.programmer@gmail.com
student-hub-node-container | startChargeTransaction failed in payments_controller.js: { error: relation "enrollments" does not exist
student-hub-node-container |     at Connection.parseE (/var/server/node_modules/pg/lib/connection.js:553:11)
student-hub-node-container |     at Connection.parseMessage (/var/server/node_modules/pg/lib/connection.js:378:19)
student-hub-node-container |     at Socket.<anonymous> (/var/server/node_modules/pg/lib/connection.js:119:22)
student-hub-node-container |     at Socket.emit (events.js:180:13)
student-hub-node-container |     at addChunk (_stream_readable.js:274:12)
student-hub-node-container |     at readableAddChunk (_stream_readable.js:261:11)
student-hub-node-container |     at Socket.Readable.push (_stream_readable.js:218:10)
student-hub-node-container |     at TCP.onread (net.js:581:20)
student-hub-node-container |   name: 'error',
student-hub-node-container |   length: 109,
student-hub-node-container |   severity: 'ERROR',
student-hub-node-container |   code: '42P01',
student-hub-node-container |   detail: undefined,
student-hub-node-container |   hint: undefined,
student-hub-node-container |   position: '8',
student-hub-node-container |   internalPosition: undefined,
student-hub-node-container |   internalQuery: undefined,
student-hub-node-container |   where: undefined,
student-hub-node-container |   schema: undefined,
student-hub-node-container |   table: undefined,
student-hub-node-container |   column: undefined,
student-hub-node-container |   dataType: undefined,
student-hub-node-container |   constraint: undefined,
student-hub-node-container |   file: 'parse_relation.c',
student-hub-node-container |   line: '1160',
student-hub-node-container |   routine: 'parserOpenTable' }
student-hub-node-container | pay_class_deposit method failed in payments_controller.js: Error: startChargeTransaction failed. However, queries were successfully rolled back and the stripe charge was refunded!
student-hub-node-container |     at Object.startChargeTransaction (/var/server/utils/payments_utils.js:119:13)
student-hub-node-container |     at <anonymous>
student-hub-node-container |     at process._tickCallback (internal/process/next_tick.js:182:7)
student-hub-node-container | POST /api/payments/class-deposit 500 2889.988 ms - 2

The record that was created in the database

ch_1Cmngk228emtMZTzIFD96ADv | Class deposit for james.lemire.programmer@gmail.com | 75000 |   | paid | 5219 | 2018-07-11 19:09:23.955138+00 | 2018-07-11 19:09:23.955138+00 | 3270 |  
-- | -- | -- | -- | -- | -- | -- | -- | -- | --

The first column is the stripe_id, followed by the description column. As you can see, they match up.

[devlemire]

P.S I appreciate the quick reply and you looking into this for me. I'm a huge fan of the massive ORM and this is a real road block right now for me!

[dmfay]

congrats, you found a bug! Script and function executors were retaining the original instance handle and weren't getting routed through the transaction. Pull down v5.1.1 and you should be all set.

[devlemire]

I'm unable to use version 5.1.1, on NPM it also says the latest is still 5.1.0. Using yarn add massive@latest provides me with 5.1.0 and doing yarn add massive@5.1.1 results in an interactive menu to choose a version with the latest being 5.1.0.

[dmfay]

I forgot I had my npmrc set up to publish to a private registry 🤦‍♀️ It's up on the public one now.

[devlemire]

Booyah! Transactions are working like a charm now! Awesome! Thanks for your speedy help, you made my boss very happy 👍