Azure / Azure/azure-functions-host
JavaScript Azure Function host does not await promise when application insights is configured
- 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
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