Twilio functions less reliable in deployed model than it is in debug mode

Hi. We are using Twilio to validate a user’s phone number. We are using the HTTP module in NodeJS to make a request to Twilio to send a message. We have found that it successfully sends the message every time when our project is running in debug mode. When we deploy our mode the message did not send. We then through sheer luck found that adding a console log before the request is over results in the deployed code working about 75% of the time.

I understand this is referencing an external service, but the issue seems to be when the code is run in debug vs deploy.

We have solved a similar issue previously where a promise statement was not being resolved causing a difference in the debug and deployed behavior. Although this seems to not be the case in our code. Previous Support Topic.

APP ID: DD9FC30D-3A6F-AB4C-FF9C-24DC92E73100

Below is a slightly simplified version of the relevant code.

    /** 
     * @param {String} firstName
     * @param {String} lastName
     * @param {String} phone
    */
    async registerUser(firstName, lastName, phone) {

        var params = {firstName, lastName, phone, email, profilePic, churchId, build};
        params = UserSupport.validate_registry_params(params);

        var user = await UserSupport.get_user_by_phone(params.phone);
        if (user) { 
            user = await update_user(user, params);
        } else {
            user = await add_user(params, 1);
        }

        if (user.churchId) {
            await resolve_users_membership(user.userId, user.churchId)
        }
        
       // THIS IS THE LOG THAT IMPROVE TEXT MESSAGE SUCCESS
        console.log(JSON.stringify(user, null, 2))

        // THIS CALLS THE TWILIO REQUEST
        await sendTextCode(user.userId);

        return get_user(user.userId);
      }
const sendTextCode = function(userId) {
    return get_user(userId, null, null, true)
    .then(async (user) => {
        let code = create_confirmation_code()
        let msg = code + ' is your verification code.'
        // sets the textcode to the user object for confirm phone
        await Backendless.Data.of("Users").save({
            "objectId": user.objectId,
            "userId": user.userId,
            "textCode": code
        })

        let phone= "+1" + user.phone;

        // THIS CALLS THE TWILIO REQUEST
        await Twilio.sendSms(phone, msg);
        return get_user(userId)
    })
}

This is the Twilio request

'use strict'

var Config = require('./_Config_')
var https = require('https')

var Twilio = {};

Twilio.sendSms = function(phone2, msg) {

    var options = {
        host: 'api.twilio.com',
        port: 443,
        path: '/2010-04-01/Accounts/' + Config.config.twilio.accountSid + '/Messages.json',
        method: 'POST',
        headers: {
          'Content-Type': 'application/x-www-form-urlencoded',
          'Authorization': 'Basic ' + new Buffer.from(Config.twilio.accountSid + ':' + Config.twilio.authToken).toString('base64')
        }
      };

    var postData = 'Body=' + msg + '&From=' + Config.config.twilio.numbers + '&To=' + phone2;

    var req = https.request(options, function(res) {
        res.setEncoding('utf8');
        res.on('data', function(data) {
          console.log('Message sent: ' + data);
        });
        res.on("error", err => {
            console.log("Error: " + err.message);
        });
    });

    req.write(postData)
    req.end()
};

module.exports = {
    Twilio
}

Hi Noah,

Have you checked in the server-side logs to see if the function perhaps is interrupted because it didn’t complete in the allotted time?

Regards,
Mark

If you are referring to the real-time backendless logs, then we don’t get an error whenever the text message doesn’t come through. My partner @Will_York explained that Twilio is showing no logging when the message is unsent (where it typically will tell us when a message is successfully sent). Will also created a small table tracking API response time to whether the message was sent or not (below). There seems to be little correlation to successful SMS messaging.
image

I’m wondering if there are any changes to the code’s environment when deployed that would cause the issue.

Also, It is worth mentioning that we also have a ‘resendCode’ API call in the same UserService that simply calls the provided ‘sendTextCode’ function. This API call seems to work almost every time.

Along with knowing that the console log before the sendTextCode call in ‘registerUser’, I wonder how the previous code including getting, updating, adding the user, and resolving the user’s membership is affecting the success of the sendTextCode function. One would think that placing the ‘await’ keywords would ensure that the functions are entirely finished before ‘sendTextCode’ is called, but maybe this isn’t the case.

The only difference between the environments is that the prod one enforces the runtime duration limit.

Most common cause for the behavior you describe is unresolved promise.

My recommendation is to (1) make sure the invocation in debug completes in the amount of time allotted in your pricing plan+time extension if any, (2) add extra logging to see where the code spends time.

Regards,
Mark

Ok, will do. Thanks for the help and quick responses. We do have a 20s time extension in our plan.