【Azure 應用服務】Azure JS Function 非同步方法中執行SQL查詢後，Callback函式中日誌無法輸出問題

問題描述

開發 Azure JS Function(NodeJS)，使用 mssql 元件運算元據庫。當SQL語句執行完成後，在Callback函式中執行日誌輸出 context.log(" ...") , 遇見如下錯誤：

Warning: Unexpected call to 'log' on the context object after function execution has completed.

Please check for asynchronous calls that are not awaited or calls to 'done' made before function execution completes. 

Function name: HttpTrigger1. Invocation Id: e8c69eb5-fcbc-451c-8ee6-c130ba86c0e9. Learn more: https://go.microsoft.com/fwlink/?linkid=2097909

錯誤截圖

 

問題解答

JS 函式程式碼(日誌無法正常輸出)

var sql = require('mssql');
var config = {
    user: 'username',
    password: 'Password',
    server: '<server name>.database.chinacloudapi.cn', // You can use 'localhost\\instance' to connect to named instance
    database: 'db name',

    options: {
        encrypt: true // Use this if you're on Windows Azure
    }
}

module.exports = async function (context, req) {
    context.log('JavaScript HTTP trigger function processed a request.');
    
    await callDBtoOutput(context);

    context.log('################');
    //Default Code ...
    const name = (req.query.name || (req.body && req.body.name));
    const responseMessage = name
        ? "Hello, " + name + ". This HTTP triggered function executed successfully."
        : "This HTTP triggered function executed successfully. Pass a name in the query string or in the request body for a personalized response.";

    context.res = {
        // status: 200, /* Defaults to 200 */
        body: responseMessage
    };
}

async function callDBtoOutput(context) {
    try {
        context.log("Some Message from callDBtoOutput")

        var ps = new sql.PreparedStatement(await sql.connect(config))
        await ps.prepare('SELECT SUSER_SNAME() ', async function (err) {
            if (err) {
                context.log(err)
            }
            context.log("start to exec sql ...from callDBtoOutput")
            await ps.execute({}, async function (err, recordset) {
                // ... error checks
                context.log(recordset)
                context.log("Login SQL DB successfully....from callDBtoOutput")
                ps.unprepare(function (err) {
                    // ... error checks
                });
            });
        });
    } catch (error) {
        context.log(`Some Error Log: from callDBtoOutput`, error);
    }
}

在 callDBtoOutput() 函式中，呼叫sql prepare 和 execute方法執行sql語句，雖然已經使用了async和await關鍵字，但根據測試結果表明：Function的主執行緒並不會等待callback函式執行。當主執行緒中context物件釋放後，子執行緒中繼續執行context.log函式時就會遇見以上警告資訊。 

 

為了解決以上prepare和execute方法中日誌輸出問題，需要使用其他執行sql的方法。在檢視mssql的官方說明(https://www.npmjs.com/package/mssql#query-command-callback)後，發現query方法能夠滿足要求。

query (command, [callback])

Execute the SQL command. To execute commands like create procedure or if you plan to work with local temporary tables, use batch instead.

Arguments

• command - T-SQL command to be executed.
• callback(err, recordset) - A callback which is called after execution has completed, or an error has occurred. Optional. If omitted, returns Promise.

 

經過多次測試，以下程式碼能完整輸出Function過程中產生的日誌。

JS 函式執行SQL程式碼(日誌正常輸出)

var sql = require('mssql');

var config = {
    user: 'username',
    password: 'Password',
    server: '<server name>.database.chinacloudapi.cn', // You can use 'localhost\\instance' to connect to named instance
    database: 'db name',

    options: {
        encrypt: true // Use this if you're on Windows Azure
    }
}

module.exports = async function (context, req) {
    context.log('JavaScript HTTP trigger function processed a request.');
    
    // context.log('call callDBtoOutput 1');
    // await callDBtoOutput(context);

    //context.log('call callDBtoOutput 2');
    await callDBtoOutput2(context);

    context.log('################');
    const name = (req.query.name || (req.body && req.body.name));
    const responseMessage = name
        ? "Hello, " + name + ". This HTTP triggered function executed successfully."
        : "This HTTP triggered function executed successfully. Pass a name in the query string or in the request body for a personalized response.";

    context.res = {
        // status: 200, /* Defaults to 200 */
        body: responseMessage
    };
}

async function callDBtoOutput2(context) {
    context.log("1: Call SQL Exec function ....")
    await sql.connect(config).then(async function () {
        // Query
        context.log("2: start to exec sql ... ")     
        await new sql.Request().query('SELECT SUSER_SNAME() ').then(async function (recordset) {
            context.log("3: Login SQL DB successfully.... show the Query result") 
            context.log(recordset);

        }).catch(function (err) {
            // ... error checks
        });
    })
    context.log("4: exec sql completed ... ") 
}

結果展示(完整日誌輸出)

 

參考資料

node-mssql: https://www.npmjs.com/package/mssql

context.done : https://learn.microsoft.com/en-us/azure/azure-functions/functions-reference-node?pivots=nodejs-model-v3&tabs=javascript%2Cwindows-setting-the-node-version#contextdone

The context.done method is deprecated

Now, it's recommended to remove the call to context.done() and mark your function as async so that it returns a promise (even if you don't await anything).