Azure / Azure/azure-functions-host

JavaScript Azure Function host does not await promise when application insights is configured

Open
#9,042 0 comments 0 reactions 0 assignees View on GitHub
bug feature:application-insights
Dominant language
C#
Stars
2k
Forks
482
Avg merge
2d 12h
Merged PRs (30d)
38

Description

#### Investigative information

- Timestamp: 2023-01-18T21:26:02Z
- Function App version: 4
- Function App name:
- Function name(s) (as appropriate): testfunction
- Invocation ID: a7c3f340-7fb0-4535-8247-4d407dc7ba4e
- Region: West US

#### Repro steps
This problem first occurred in the cloud, but is also reproducible locally using the local functions runtime

I have provided code relating to this example, of a simple azure function with an HTTP trigger below.
Note that at the top of the module applications insights is initialised

This was run locally with the following environment
- ubuntu 20.04 under wsl2, Windows 11 Pro
- npx func --version : 4.0.4915
- node --version: v16.14.1

## Example 1: With Application Insights initialised
1. Start the function locally
- ```npm run start```
3. Trigger the http function
- ```npm run hit-me```
- or ```curl curl http://localhost:7071/api/test```
5. The function responds with http body **NO** we expect it to respond with **YES**
6. Logs
```
[2023-01-18T20:33:58.508Z] =====START=====================
[2023-01-18T20:33:58.514Z] Executed 'Functions.testfunction' (Succeeded, Id=e4352847-ce68-4d26-b32f-f4645dcb1d93, Duration=17ms)
[2023-01-18T20:33:59.009Z] Timeout resolved
[2023-01-18T20:33:59.009Z] Done
[2023-01-18T20:33:59.009Z] ===END: Console=======================
[2023-01-18T20:33:59.011Z] 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: testfunction. Invocation Id: e4352847-ce68-4d26-b32f-f4645dcb1d93. Learn more: https://go.microsoft.com/fwlink/?linkid=2097909
```

7. **NOTE** that the function exits immediately without waiting for the functions returned promise (function execution 17ms)

## Example 2: Without Application Insights initialized
1. Comment out the code to initialise applications insights
- ```// appInsights.setup(myAppinsightsKey).start()```
1. Start the function locally
- ```npm run start```
1. Trigger the http function
- ```npm run hit-me```
- or ```curl curl http://localhost:7071/api/test```
1. The function responds with http body **YES** as expected (function execution 645ms)
```
[2023-01-18T20:34:12.653Z] =====START=====================
[2023-01-18T20:34:13.155Z] Timeout resolved
[2023-01-18T20:34:13.155Z] Done
[2023-01-18T20:34:13.155Z] ===END: Console=======================
[2023-01-18T20:34:13.163Z] ===END: Context=======================
[2023-01-18T20:34:13.165Z] Executed 'Functions.testfunction' (Succeeded, Id=b0cfaa8a-79ad-4a43-ba80-abf808edaca9, Duration=685ms)
```

#### Expected behaviour

The function host should always wait for the functions returned promise to complete

#### Actual behaviour

When applications insights is configured the function host does not wait for the functions returned promise before completing, thus the HTTP triggered function does not return the correct result

#### Known workarounds

Do not use application insights

#### Related information

Provide any related information

* Programming language used: Node/javascript
* Links to source: source provided below: See also attached zip file
* Bindings used: Httptrigger

I have tried using `await` and `then` promise syntax
I have tried using `$return` output binding as well as setting the binding output
I have tried various different applications insights configuration none have altered this behaviour

In all cases the above observed behaviour remains the same

Source

index.js
```javascript
const appInsights = require("applicationinsights")

const myAppinsightsKey =""

// Comment out line below to get expected results
appInsights.setup(myAppinsightsKey).start()

module.exports = async function (context, req) {
try{
console.log("=====START=====================")
context.bindings.res = {status: 200,body: "NO\n"}

await testFunction()
.then(() =>{
console.log("Done")
context.bindings.res = {status: 200,body: "YES\n"}
console.log("===END: Console=======================")
context.log("===END: Context=======================")
})
} catch(err) {
context.res = {status: 500, body: "Woops\n"}
console.log("===END: Error=======================")
}
}

function testFunction() {
return new Promise((resolve) => {
setTimeout(() => {
console.log("Timeout resolved")
resolve()
}, 500)
})
}
```

function.json
```json
{
"bindings": [
{
"authLevel": "function",
"type": "httpTrigger",
"direction": "in",
"name": "req",
"methods": [
"get",
"post"
],
"route": "test"
},
{
"type": "http",
"direction": "out",
"name": "res"
}
],
"scriptFile": "./index.js",
"disabled": false
}
```
host.json
```json
{
"version": "2.0",
"logging": {
"applicationInsights": {
"samplingSettings": {
"isEnabled": true,
"excludedTypes": "Request"
}
}
},
"extensionBundle": {
"id": "Microsoft.Azure.Functions.ExtensionBundle",
"version": "[3.*, 4.0.0)"
}
}
```
package.json
```json
{
"name": "test-azurefunc-appinsights",
"version": "1.0.0",
"description": "",
"scripts": {
"start": "func start",
"test": "echo \"No tests yet...\"",
"clean": "rm -rf node_modules",
"hit-me": "curl http://localhost:7071/api/test"
},
"dependencies": {
"applicationinsights": "~2.4.0"
},
"devDependencies": {
"azure-functions-core-tools": "^4.x"
}
}
```
local.settings.json
```json
{
"IsEncrypted": false,
"Values": {
"FUNCTIONS_WORKER_RUNTIME": "node",
"AzureWebJobsStorage": "UseDevelopmentStorage=true",
"AzureWebJobsDashboard": "UseDevelopmentStorage=true"
}
}
```

[testFunction.zip](https://github.com/Azure/azure-functions-host/files/10451515/testFunction.zip)

Contributor guide

Open the contributing guide

Research direction

Start with the supplied index.js reproduction and its function.json binding, then run npm start and npm run hit-me with and without appInsights.setup(...). Trace the host's handling of the async function and Application Insights configuration. Done means the HTTP function waits for the returned promise and responds YES in both cases.

Written by the indexing model from the issue text.

Assessment

Tech stack
azure, javascript, node.js
Domain
backend, cloud, observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.