We are hosting a REST API written in Python on Azure Functions, and using logging to monitor it.
Sometimes, not all of the expected output is displayed in Application Insights.
Here is an example of what it should look like:
2021-10-26T18:44:13Z [Verbose] Sending invocation id:64be8d30-a3ff-41d0-a653-de20c48db85a
2021-10-26T18:44:13Z [Verbose] Posting invocation id:64be8d30-a3ff-41d0-a653-de20c48db85a on workerId:834c70c0-d3bd-4dab-89b6-c8cb77c2f6a7
2021-10-26T18:44:13Z [Information] ****************************************************************
2021-10-26T18:44:13Z [Information] AzureResourceClient initialized in: 0 milliseconds
2021-10-26T18:44:13Z [Information] Timer: INIT elapsed time: 228 milliseconds
2021-10-26T18:44:13Z [Information] INVOCATION: 581aa19c-05c3-4e3a-a47b-13c6523c141c
2021-10-26T18:44:13Z [Information] METHOD & URL: ...
2021-10-26T18:44:13Z [Information] USER & COMPANY: ...
2021-10-26T18:44:13Z [Information] REQUEST COMPANY: ...
2021-10-26T18:44:13Z [Information] COLLECTION & ITEM: ...
2021-10-26T18:44:13Z [Information] ACTION: ...
2021-10-26T18:44:13Z [Information] AzureResourceClient total requests made: 2, accumulated x-ms-request-charge: 4.16 (avg 2.08 per request)
2021-10-26T18:44:13Z [Information] Timer: MAIN elapsed time: 229 milliseconds
2021-10-26T18:44:13Z [Information] Executed 'Functions.main' (Succeeded, Id=581aa19c-05c3-4e3a-a47b-13c6523c141c, Duration=246ms)
And here is an example of truncated output:
2021-10-26T18:44:13Z [Verbose] Sending invocation id:fd430857-1f0c-47c9-9ec8-47dcb17c767c
2021-10-26T18:44:13Z [Verbose] Posting invocation id:fd430857-1f0c-47c9-9ec8-47dcb17c767c on workerId:834c70c0-d3bd-4dab-89b6-c8cb77c2f6a7
2021-10-26T18:44:13Z [Information] ****************************************************************
2021-10-26T18:44:13Z [Information] AzureResourceClient initialized in: 0 milliseconds
2021-10-26T18:44:13Z [Information] Timer: INIT elapsed time: 290 milliseconds
2021-10-26T18:44:13Z [Information] INVOCATION: 64be8d30-a3ff-41d0-a653-de20c48db85a
... that's it. It just stops. The API call finishes correctly though--we have no reason to believe there's an error or exception.
We think the issue is possibly related to the stdout not being flushed, but calling logging.StreamHandler(stream=sys.stdout).flush() before returning the HTTP response has no effect.
How can we ensure that all of the expected output makes it to Application Insights?
BONUS: the output is often delayed by tens of seconds (in some cases several minutes). How can we ensure that the logging output is available instantly and in order of execution?
