Azure Function execution speed is extremely slow and inconsistent

Question

I am writing few Azure Functions script that reads and write from/to an internal database and display relevant information into a webpage.

I noticed extreme slowness or even timeout in the web UI when loading the web page which calls the Azure Function script. After further investigation, I realized that the following:

1. Azure Function scripts sometimes takes anywhere between 10 seconds to more than 1 minutes to connect to SQL database.
2. Sometimes the scripts will run in few millisecond and sometimes it will take more than 3 minutes to completely run the script.

Here is my Azure Function script:

module.exports = function(context, req) {

context.log("Function Started: " + new Date());

// Import package
const sql = require('mssql');
var _ = require('underscore-node');
var moment = require('moment');
var Promise = require('promise');
// Create a configuration object for our Azure SQL connection parameters
var config = {
    server: "***", // Use your SQL server name
    database: "***", // Database to connect to
    user: "***", // Use your username
    password: "***", // Use your password
    port: ***,
    // Since we're on Windows Azure, we need to set the following options
    options: {
        encrypt: true
    },
    multipleStatements: true,
    parseJSON: true
};
var flagDefinitionId = null;

if (req.query.Id == null || req.query.Id == "" || req.query.Id.length == 0) {
    context.res = {
        // status: 200, /* Defaults to 200 */
        body: "No have flagDefinitionId "
    };
    context.done();
    // return;
}

var listTicketsFlag = [];

flagDefinitionId = req.query.Id;
sql.close();
var DBSchema = "b8akjsms2_st.";
sql.connect(config).then(function() {
    context.log("SQL Connected: " + new Date());

    var getAllEventTicketGoToMarket = new Promise(function(resolve, reject) {
        var queryGetEvent = ";WITH EventLog1 AS(" +
            " SELECT MD1, max([DateTime]) as LTime from " + DBSchema + "EventLog" +
            " where ([Event] = 'Ticket_Go_To_Market' OR [Event] = 'Acknowledge_Timeout')" +
            " group by MD1 )" +
            " SELECT * from ( SELECT EV.MD1 , EV.MD2," +
            " (SELECT COUNT(*) from " + DBSchema + "EventLog where MD1 = EV.MD1 and [Event] = 'Market_Ticket_Clear') as TotalClear" +
            " FROM " + DBSchema + "[Ticket] T" +
            " JOIN (SELECT E.* from " + DBSchema + "EventLog E join EventLog1 E1 on E.MD1 = E1.MD1 and E.[DateTime] = E1.LTime) EV ON T.Id = EV.MD1" +
            " WHERE T.IsInMarket = 1 and EV.MD2 <> ''" +
            " AND T.Id NOT IN (Select TicketId from " + DBSchema + "TicketFlag where FlagDefinitionId = " + flagDefinitionId + ")" +
            " ) R where R.TotalClear > 0";
        context.log("get event log - Ticket_Go_To_Market" + queryGetEvent);
        new sql.Request().query(queryGetEvent, (err, result) => {
            context.log("this is --------> EventLog " + result.recordset.length);
            resolve(result.recordset);
        });
    });

    Promise.all([getAllEventTicketGoToMarket]).then(function(values) {
        var ticketGoToMarket = values[0];
        context.log("this is --------> values: " + values[0].length + " ==+++++==== " + JSON.stringify(values[0], null, 2));

        if (ticketGoToMarket.length != 0) {
            listTicketsFlag = _.filter(ticketGoToMarket, function(num) {
                var countSP = num.MD2.split(',');
                // context.log("countSP =====> " + countSP.length + "num.TotalClear ==>" + num.TotalClear)
                if (num.TotalClear > countSP.length) {
                    return num.MD1;
                }
            });
            // context.log("listTicketsFlag =====> " + JSON.stringify(listTicketsFlag, null, 2));
        }
        insertTicketFlag();

    });

    function insertTicketFlag() {
        context.log("this is ----- ===> Insert:  " + listTicketsFlag);
        // insert
        var insertTicketFlagPromise = new Promise(function(resolve, reject) {

            context.log("listTicketFlag ----- ===> " + listTicketsFlag.length);

            if (listTicketsFlag.length == 0) {
                context.log(" -------------------- No have ticket need FLAG");
                resolve();

            } else {

                // insert new data to TicketFlag FlagTickets
                var listTicketInsert = ""; //convertArrayToSQLString(listTicketsFlag, true, flagDefinitionId);
                var len = listTicketsFlag.length - 1;
                for (var j = 0; j <= len; j++) {
                    listTicketInsert += '(\'' + listTicketsFlag[j] + '\', \'' + flagDefinitionId + '\')';
                    if (j != len) {
                        listTicketInsert += ",";
                    }
                }
                context.log("HERE : " + listTicketInsert);

                var insertQuery = 'Insert into  ' + DBSchema + '[TicketFlag] (TicketId, FlagDefinitionId) values ' + listTicketInsert + '';

                context.log("this is --------> InsertQuery" + insertQuery);

                // return;

                context.log("read data of FlagRule");
                new sql.Request().query(insertQuery, (err, result) => {
                    context.log("this is --------> insertQuery");
                    resolve(result);

                });
            }
        });

        Promise.all([insertTicketFlagPromise]).then(function(values) {
            context.log("DONE ALL");
            sql.close();
            context.done();
        })
    }

}).catch(function(err) {
    console.log(err);
    context.done();
});

};

How can resolve this slowness issue?

Answer 1

We have noticed this as well with our node.js Functions. After a lot of research and testing here is what we've found:

1. Function Apps go into a "cold" state after five minutes of inactivity. When they come out of the cold state you can expect up to 10 seconds of what seems to be compilation/transpilation of node JavaScript into .Net code so they can run natively inside the greater Function engine. Note that I said "Function App" above and not merely "Function"

2. Even if it's in a "hot" state (i.e. < 5 minutes idle time), there are occasions that the Function will take an excessive amount of time to load external libraries

3. The biggest culprit in this performance hit is larger external libraries with many small files.

So what can you do to alleviate this? Here is what we have done in order of complexity:

1. Set up a timer Function that executes in a time frame less than 5 minutes. We run a simple timer every four minutes that takes anywhere between 0ms and 10ms and you can do the math to see that's a VERY cheap way to keep your Function App in a hot state.

2. Use the Functions-Pack package to consolidate all of your external libraries into a single file. When the Function is re-compiled or transpiled or whatever magic happens back there it gets much faster as it doesn't have to seek dozens or hundreds of files.

3. Using REST API's instead of SDK's means zero external libraries are required. The big issue with that is generating the Authorization headers, there is no standard across Azure for how to form an Auth header and this part of their docs is barely covered in most cases, especially with node.js. I've thought about starting a github repository purely for node.js code that generates various Azure Auth tokens.

4. Port your Functions to C# (yeah, I'm not happy with this option either - I want an all JavaScript/TypeScript platform for our product). Still, remove the cross-compilation/transpilation/whatever and it's supposed to speed up dramatically. I'm porting one of our most complex Functions over to C# now to further test this theory.

5. Moving to an App Service Plan seems counter-intuitive to the value of Azure Functions. I want unlimited scale that Microsoft handles and a per-execution cost. App Service plan forces me to think about CPU's and memory and App Capacity again.

Here is an MSDN forums thread that I posted requesting feedback on our issues.