Knex Record Insertion Excecuting Out of Order

Question

I'm seeing some weird async behavior when attempting to add a record with Knex in my tests.

When the POST /api/v1/chats route is hit a chat is created and added to the chat table. Additionally, the user ids (there are 2 of them) passed to the route handler in the request body and the id of the newly created chat are used to add two association entities to the user_chat table: { user_id: 2, chat_id: 3 } and { user_id: 4, chat_id: 3 }. To record the fact that the users with the ids of 4 and 2 are in the chat with id of 3.

However, the addUserChat method/query is not executing in the way I expect it to. As can be seen in the console, ie console logs from the the beginning of that function call happen twice before the first time console logs from the end of the function happen once.

Obviously there is some asynchronous call that isn't being resolved before the next one takes control. But I am having difficulty tracking down where this is happening. It would seem to me that this shouldn't be an issue as I'm awaiting the creation of the user_chat record in line 13 but obviously I'm wrong as the behavior is way off.

I am curious how I might resolve this such that the routine runs in order and both my user_chat are inserted as expected.

addUserChat: https://github.com/caseysiebel/lang-exchange/blob/master/src/server/db/queries/user_chat.js#L7

addUserChat: ( async (user_id, chat_id) => {
    console.log()
    console.log('====================================================================================================')
    console.log('in query')
    console.log('user_id', user_id)
    console.log('chat_id', chat_id)
    console.log()
    console.log('before await userChats')
    const user_chat = await userChats
        .insert({ user_id, chat_id })
        .returning('*')
    console.log('after await userChats')
    console.log('user_chat', user_chat);
    console.log()

    const data = await db('user_chat').select('*')
    console.log('data', data)
    console.log('****************************************************************************************************')
    console.log()

    return user_chat;
}),

Console output (https://gist.github.com/caseysiebel/262997efdd6467c72304ee783dadd9af#file-console-L5) :

====================================================================================================
in query
user_id 2
chat_id 3

before await userChats

====================================================================================================
in query
user_id 4
chat_id 3

before await userChats
after await userChats
user_chat [ anonymous { id: 5, user_id: '4', chat_id: '3' } ]

after await userChats
user_chat [ anonymous { id: 6, user_id: '4', chat_id: '3' } ]

data [ anonymous { id: 1, user_id: '1', chat_id: '1' },
  anonymous { id: 2, user_id: '2', chat_id: '2' },
  anonymous { id: 3, user_id: '3', chat_id: '2' },
  anonymous { id: 4, user_id: '4', chat_id: '1' },
  anonymous { id: 5, user_id: '4', chat_id: '3' },
  anonymous { id: 6, user_id: '4', chat_id: '3' } ]
****************************************************************************************************

data [ anonymous { id: 1, user_id: '1', chat_id: '1' },
  anonymous { id: 2, user_id: '2', chat_id: '2' },
  anonymous { id: 3, user_id: '3', chat_id: '2' },
  anonymous { id: 4, user_id: '4', chat_id: '1' },
  anonymous { id: 5, user_id: '4', chat_id: '3' },
  anonymous { id: 6, user_id: '4', chat_id: '3' } ]
****************************************************************************************************

Other relevant code would be the POST /api/v1/chat route handler:

router.post('/api/v1/chat', async (ctx) => {
    try {
        const { created_at , user_ids } = ctx.request.body;
        const chat_list = await queries.addChat({ created_at });
        const chat = chat_list[0];
        if (chat) {
            ctx.status = 201;
            ctx.body = {
                status: 'success',
                data: chat
            };
            try {
                console.log('user_ids', user_ids)
                await Promise.all(user_ids.map((user_id) => {
                    return user_chat_queries.addUserChat(user_id, chat.id)
                }));
            }
            catch (err) {
                ctx.status = 400;
                ctx.body = {
                    status: 'error',
                    message: err.chat || 'Sorry, an error has occured.'
                };
            }
        }
        else {
            ctx.status = 400;
            ctx.body = {
                status: 'error',
                message: 'Something went wrong.'
            };
        }
    }
    catch (err) {
        ctx.status = 400;
        ctx.body = {
            status: 'error',
            message: err.chat || 'Sorry, an error has occured.'
        };
    }
})

The Test for the chat route where the call is is inciated

it('should add 2 user_chats', (done) => {
            console.log('00000000000000000000000000000000000000000000000000')
            chai.request(server)
                .post('/api/v1/chats')
                .send({
                    created_at: Date.now(),
                    user_ids: [ 2, 4 ]
                })
                .end((err, res) => {
                    should.not.exist(err);
                    res.status.should.equal(201);
                    res.type.should.equal('application/json');
                    res.body.status.should.eql('success');
                    const chat = res.body.data;
                    chat.should.include.keys('id', 'created_at');
                    let num_user_chats = 0;

                    console.log('&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&')
                    console.log('chat', chat)
                    console.log('chat.id', chat.id)
                    console.log('&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&')
                    knex('user_chat')
                        .select('*')
                        .then((data) => console.log('data', data))

                    knex('user_chat')
                        .where('user_id', 2)
                        .select('*')
                        .then((data) => console.log('data', data))

                    console.log('user_chat', user_chat);

                    done();
                });
        });

All the code for the project: https://github.com/caseysiebel/lang-exchange

Answer 1

If I got the question right, your problem is that you do not want to run multiple addUserChat calls parallel.

The place where you make them run parallel is here:

await Promise.all(user_ids.map((user_id) => {
    return user_chat_queries.addUserChat(user_id, chat.id)
}));

To run them sequentially you could do:

for (let user_id of user_ids) {
  await user_chat_queries.addUserChat(user_id, chat.id)
}

Another better way to make them run sequentially would be using transactions.

EDIT understood the real problem after @Casey's comment:

I suppose that your userChats is some predefined query builder. So you are using the same builder again and again with all separate insert.

So basically on first user id your query is like:

const user_chat = await userChats
    .insert({ user_id, chat_id }) // user_id = 2 
    .returning('*')

And in second round it is:

const user_chat = await userChats
    .returning('*')
    .insert({ user_id, chat_id }) // user_id = 2 
    .insert({ user_id, chat_id }) // user_id = 4
    .returning('*');

Now this second query is actually built before first query is emitted so effectively the both queries are the same:

const user_chat = await userChats
    .returning('*')
    .insert({ user_id, chat_id }) // user_id = 2 
    .insert({ user_id, chat_id }) // user_id = 4
    .returning('*');

You can fix that by remembering to make clone of your builder for each query:

const user_chat = await userChats.clone()
    .insert({ user_id, chat_id })
    .returning('*')