I'm not sure if it's a bug or some obscure setting I haven't found yet but I am getting different log behaviours for identical calling parameters. I set up a script to call an endpoint every 3 seconds with the same payload. On first call where there is a cold start I see:
2020-03-05 22:04:13.262 Handler processing a request for: transform
2020-03-05 22:04:21.840 Handler processing a request for: transform
2020-03-05 22:04:21.840 Received message: Message(<snip>)
2020-03-05 22:04:21.841 Successful metrics: 1 Unsuccessful metrics: 0
2020-03-05 22:04:22.497 Function "transform" (Id: 98d6e618-637f-4104-81b5-a67f2701bb81) invoked by Java Worker
On several subsequent calls I just see:
2020-03-05 22:04:24.216 Handler processing a request for: transform
2020-03-05 22:04:24.217 Function "transform" (Id: c1f4f7d0-b36e-4be4-bd38-aeebc5117900) invoked by Java Worker
Here's my host.json:
{
"version": "2.0",
"functionTimeout": "00:10:00",
"extensionBundle": {
"id": "Microsoft.Azure.Functions.ExtensionBundle",
"version": "[1.*, 2.0.0)"
},
"logging": {
"fileLoggingMode": "always",
"logLevel": {
"default": "Information",
"Host.Results": "Trace",
"Function": "Warning",
"Function.transform.User": "Information",
"Host.Aggregator": "Trace"
},
"applicationInsights": {
"samplingSettings": {
"isEnabled": true,
"maxTelemetryItemsPerSecond": 50
}
}
}
}
What could be the problem? The sampling settings did not affect the behaviour. The problem is that the messages such as "Received message..." are the important ones.
I also looked in the kudu app dump for the function and the logging is also incomplete there.