Doing abusive testing on my functions, and I noticed what seems like a lot of overhead difference in the execution times reported in the Azure logs vs what I am measuring at the client side. On average, there is 200-300 milliseconds more measured at the client than reported in the logs. Is this expected behavior, or is there some setting I am missing that could cause this?
Azure Logs:
Connected!
2022-09-22T16:12:58.677 [Information] Executing 'TheFunction' (Reason='This function was programmatically called via the host APIs.', Id=0192e3cc-a5b5-4642-baa3-af1288167530)
2022-09-22T16:12:58.693 [Information] Enter THE Function
2022-09-22T16:12:58.694 [Information] Call Init()
2022-09-22T16:12:59.447 [Warning] Enter CreateRepository, No cached repository available!
2022-09-22T16:13:03.778 [Information] Executed 'TheFunction' (Succeeded, Id=0192e3cc-a5b5-4642-baa3-af1288167530, Duration=5137ms)
2022-09-22T16:13:14.353 [Information] Executing 'TheFunction' (Reason='This function was programmatically called via the host APIs.', Id=c0288ce8-3961-4c48-9f2e-4f39e0137e1d)
2022-09-22T16:13:14.354 [Information] Enter THE Function
2022-09-22T16:13:14.354 [Warning] Enter CreateRepository, Using Cached Repository
2022-09-22T16:13:14.357 [Information] Executed 'TntFunction' (Succeeded, Id=c0288ce8-3961-4c48-9f2e-4f39e0137e1d, Duration=7ms)
On the first call, it is a cold start, so we get a hefty 5137ms. The second call sends the same payload, so with caching we turn in a respectable 7ms.
On the client side, testing with curl, I get the following times:
$ time cat data/1663863194_request | curl -s -X POST -d@- -H 'Content-Type: application/json' https://some-azure-url
real 0m5.620s
$ time cat data/1663863194_request | curl -s -X POST -d@- -H 'Content-Type: application/json' https://some-azure-url
real 0m0.282s
Currently using consumption plan with SKU Y1 which I believe is Windows based.