【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).