monkey
monkey

Reputation: 1597

Unpredictable execution of async code in Lambda node.js

I cannot understand how to use async code in Lambda. The results are baffling, Let's build 2 functions:

const sendToFirehoseAsync = async (param) => {
    console.log(param);
    const promise = new Promise(function(resolve, reject) {

        var params = {
            DeliveryStreamName: 'TestStream', 
            Records: [{ Data: 'test data' }]
        };
        console.log('params', params);

        firehose.putRecordBatch(params, function (err, data) {
            if (err) console.log(err, err.stack); // an error occurred
            else console.log('Firehose Successful',  data);           //         successful response
        });
    });
    return promise;
}

and

const sendToFirehoseSync = (param) => {
    console.log(param);

    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data' }]
    };
    console.log('params', params);

    firehose.putRecordBatch(params, function (err, data) {
        if (err) console.log(err, err.stack); // an error occurred
        else console.log('Firehose Successful',  data);           //         successful response
    });  
}

Now Let's run them up and see what happens!

Run Async function - It works fine.

exports.handler = async (event) => {
    let res = await sendToFirehoseAsync('test1');
    return res;
}

    2020-11-05T20:19:16.146+13:00   START RequestId: e4c505ea-1717-4998-ad0d-a42434f0a0c1 Version: $LATEST
    2020-11-05T20:19:16.148+13:00   2020-11-05T07:19:16.147Z e4c505ea-1717-4998-ad0d-a42434f0a0c1 INFO test1
    2020-11-05T20:19:16.149+13:00   2020-11-05T07:19:16.149Z e4c505ea-1717-4998-ad0d-a42434f0a0c1 INFO params { DeliveryStreamName: 'TestStream', Records: [ { Data: 'test data' } ] }
    2020-11-05T07:19:16.245Z    e4c505ea-1717-4998-ad0d-a42434f0a0c1    INFO    Firehose Successful {
        FailedPutCount: 0,
        Encrypted: false,
        ....

However, if I call the function twice with await (see below), I get exactly the same response (i.e. I do not see the console.log for test 2, etc. It's as if the second call never happens? What's going on? I assumed await would halt execution until the first function resolved, and then continue on. Clearly not.

let res = await sendToFirehoseAsync('test1');
res = await sendToFirehoseAsync('test2');
return res;

Now let's run a few more back to back:

console.log('async call 1');
await sendToFirehoseAsync('test1');

console.log('async call 2');
await sendToFirehoseAsync('test2');

console.log('sync call 1');
let resp1 = await sendToFirehoseSync('1');

console.log('sync call 2');
let resp2 = await sendToFirehoseSync('2');

console.log('after sync calls');

2020-11-05T20:35:28.465+13:00   2020-11-05T07:35:28.464Z 5a9e551f-ecc6-4f18-8af4-a11b1b29d835 INFO async call 1
2020-11-05T20:35:28.465+13:00   2020-11-05T07:35:28.465Z 5a9e551f-ecc6-4f18-8af4-a11b1b29d835 INFO test1
2020-11-05T20:35:28.467+13:00   2020-11-05T07:35:28.467Z 5a9e551f-ecc6-4f18-8af4-a11b1b29d835 INFO params { DeliveryStreamName: 'TestStream', Records: [ { Data: 'test data' } ] }
2020-11-05T20:35:28.577+13:00   2020-11-05T07:35:28.577Z 5a9e551f-ecc6-4f18-8af4-a11b1b29d835 INFO Firehose Successful { FailedPutCount: 0, Encrypted: false, RequestResponses: [ { RecordId: '4v+6H3T3koBggYYvdu/U6fg4h0C8m4taPVYznfYT4fIAWmm9XKu4/9F9jEgjdZFE02IsNgYs0/ORGzz1l2udEzCJUN1dRR1YCHSi/jiLI/DHGpTkoyN89VUG0jGzNlAERgUNCIwxXlCYww/l2HSGjK8++f+qmRj7sTCY/J4/QlV2sqhcXSlJjKhkK+A+Ib7w2+WwdZ5gliF64fSP9qkQSpeSutOh68o6' } ] }
2020-11-05T20:35:28.580+13:00   END RequestId: 5a9e551f-ecc6-4f18-8af4-a11b1b29d835

Again, only 1 result comes back. The rest are lost?!

And I get the same result with 2 async calls, followed by 2 sync calls and one more for good measure.

console.log('async call 1');
await sendToFirehoseAsync('test1');

console.log('async call 2');
await sendToFirehoseAsync('test2');

console.log('sync call 1');
let resp1 = await sendToFirehoseSync('1');

console.log('sync call 2');
let resp2 = await sendToFirehoseSync('2');

console.log('after sync calls');


const promise = new Promise(function(resolve, reject) {

    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data 2' }]
    };
    console.log('params', params);

    firehose.putRecordBatch(params, function (err, data) {
        if (err) console.log(err, err.stack); // an error occurred
        else console.log('Firehose Successful',  data);           //         successful response
    });
});

return promise;  

However... If I rerun the last example but comment out the 2 async calls, I get something different...

console.log('sync call 1');
let resp1 = await sendToFirehoseSync('1');

console.log('sync call 2');
let resp2 = await sendToFirehoseSync('2');

console.log('after sync calls');


const promise = new Promise(function(resolve, reject) {

    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data 2' }]
    };
    console.log('params', params);

    firehose.putRecordBatch(params, function (err, data) {
        if (err) console.log(err, err.stack); // an error occurred
        else console.log('Firehose Successful',  data);           //         successful response
    });
});

return promise;

2020-11-05T20:42:08.713+13:00
2020-11-05T07:42:08.713Z    333feae9-f306-409c-89c8-1707e0547ba3    INFO    sync call 1
2020-11-05T07:42:08.713Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO sync call 1
2020-11-05T20:42:08.713+13:00   2020-11-05T07:42:08.713Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO 1
2020-11-05T20:42:08.715+13:00   2020-11-05T07:42:08.715Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO params { DeliveryStreamName: 'TestStream', Records: [ { Data: 'test data' } ] }
2020-11-05T20:42:08.760+13:00   2020-11-05T07:42:08.760Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO after sync calls
2020-11-05T20:42:08.760+13:00   2020-11-05T07:42:08.760Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO params { DeliveryStreamName: 'TestStream', Records: [ { Data: 'test data 2' } ] }
2020-11-05T20:42:08.808+13:00   2020-11-05T07:42:08.807Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO Firehose Successful { FailedPutCount: 0, Encrypted: false, RequestResponses: [ { RecordId: 'iWeCDK6kukfkLfh/1mg791g3sIVpDC1hNNokJuTGFJJaLBNd1TvvCiWHV4z2iiWS3hOvu9OmKVnUofCPbr5uewKPAQBdiCJp9iVIzTakcL5bb4CkyOZKxzLX4NOxTP94Z0j64KgssWo10z7jEhDoevF8NTMZR+tUlhHmYtEGcQq2YViwwXhpYX8MP4yvS5xSRo+sjJXEcyoty+Pvt1UFWGelEKIygtnO' } ] }
2020-11-05T20:42:08.865+13:00   2020-11-05T07:42:08.865Z 333feae9-f306-409c-89c8-1707e0547ba3 INFO Firehose Successful { FailedPutCount: 0, Encrypted: false, RequestResponses: [ { RecordId: 's5loZTT8d4J0fhSjnJli0LzOzljnvgvC99AvdSeqkj/j9xp5RnjstL5UxQXm5t+uyEbSSe21XZxwaUU/D7XVsCzpJ6F5nlnzsOZBLd6vyaF3bc2lSUo2DM2u9dGetJPMahC1b0rO+GXod91sC9XumS8QWIVePcww2DH0IM46RuoLEVVR3/kgcnvhIm/UU67JuvZkFTCAP/jss0VwVUY2vmzfdvw4mJT4' } ] }
2020-11-05T20:42:08.867+13:00   END RequestId: 333feae9-f306-409c-89c8-1707e0547ba3

The only pattern I can see is the return. The async function has a return in it. Does that perhaps cause the entire lambda to return, not just the function? I hope this (unfortunately) long experiment will be helpful and that someone can shed some light on how this works. Cheers.

** Adding Resolve & Reject **

console.log('before');
await sendToFirehosePromise('thing');
console.log('after');

....

async function sendToFirehosePromise(record) {
    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data' }]
    };
    
    const promise =  new Promise((resolve, reject) => {
        firehose.putRecordBatch(params, (err, data) => {
            if (err) return reject(err);
            return resolve(data);
        });
    });       
    return promise;
}

Upvotes: 1

Views: 349

Answers (1)

404
404

Reputation: 8542

Let's cut it down as much as possible to pure async calls from a lambda:

function f(p) {
    console.log(p);
    return new Promise(res => res('result ' + p));
}

exports.handler = async () => {
    let res = await f(1);
    console.log(res);
    res = await f(2);
    console.log(res);
    res = await f(3);
    console.log(res);
}

Prints:

2020-11-05T10:40:25.298Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    1
2020-11-05T10:40:25.298Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    result 1
2020-11-05T10:40:25.298Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    2
2020-11-05T10:40:25.298Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    result 2
2020-11-05T10:40:25.298Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    3
2020-11-05T10:40:25.299Z    bd564d91-480f-4dcd-8134-1481fa59a946    INFO    result 3

Now compare it yours. Firstly this signature is wrong (or at least unnecessary): const sendToFirehoseAsync = async (param). Async is only required if you await something. If you're not awaiting - and you're not - you don't need to mark it async. An async function can await anything that returns a promise. If your function returns a promise and doesn't await anything then don't mark it async.

Now to the part where you're mixing promises and async unnecessarily.

async function sendToFirehosePromise(record) {
    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data' }]
    };
    
    const promise =  new Promise((resolve, reject) => {
        firehose.putRecordBatch(params, (err, data) => {
            if (err) return reject(err);
            return resolve(data);
        });
    });       
    return promise;
}

If you're trying to use async, use async. All AWS SDK calls return a type of AWS.Request. That type contains a promise() method. You can await that promise rather than using actual promise notation.

async function sendToFirehosePromise(record) {
    var params = {
        DeliveryStreamName: 'TestStream', 
        Records: [{ Data: 'test data' }]
    };
    return await firehose.putRecordBatch(params).promise();
}

That's a proper use of async/await with the SDK rather than shoehorning it into custom promises. Now in your handler you can await that function as many times as you want and it will always work.

Upvotes: 1

Related Questions