Azure-webjobs-sdk: Log APIs taking way to long to return data

[mathewc]

In the functions portal Monitor tab, pulling log data for a simple function that has had less than 10 execution is taking around 8 to 10 seconds to load.

I've verified that the issue isn't the portal itself, but the actual log API itself on the SCM endpoint, e.g.:

https://<mysite>.scm.azurewebsites.net/azurejobs/api/functions/definitions?host=<mysite>&limit=11

This query is taking 8 to 10 seconds. Since this is only issuing a few table queries, it should be able to return in under a second. We need to find out where we're spending the time.

I even went in and deleted my old v1 log table, as well as the one previous month table, so I now only have a single log table AzureWebJobsHostLogs201611, in addition to AzureWebJobsHostLogscommon.

[mathewc]

One important finding that @davidebbo pointed out was that it isn't the log retrieval query that is slow, it's the query to return function definitions (definitions link above). The log query turns out to be fast:

https://<mysite>.scm.azurewebsites.net/azurejobs/api/functions/definitions/function:2Dfun-queuetriggerpython/invocations?limit=20

Why does the monitor tab for a specific function need to query the definitions endpoint? My function app has about 20 functions in it. @davidebbo found in his function app with 4 functions that he wasn't seeing this slowness.

[MikeStall]

I'm also looking at https://github.com/Azure/azure-webjobs-sdk/issues/929, which is the opposite of this (in that one, /definitions is fast and /invocations is the slow one).

[MikeStall]

The slowdown is here: https://github.com/Azure/azure-webjobs-sdk/blob/dev/src/Dashboard/ApiControllers/FunctionsController.cs#L523
After getting the function definitions, we do a fan out to get stats on each definition. So it slows down with the number of definitions.

[ebashmakov]

@mathewc @MikeStall

Also it seems like limit parameter doesn't work here: https://{sitename}.scm.azurewebsites.net/azurejobs/api/functions/definitions/{function-name}/invocations?limit=20
it returns all entries or a timeout.

[MikeStall]

@ebashmakov - I think that issue is https://github.com/Azure/azure-webjobs-sdk/issues/929 , which was recently fixed.
That said - we're not encouraging people to call the REST APIs directly yet - they need to be polished up.

[ebashmakov]

@MikeStall is it on the production already?
(I didn't call it directly. It's called from Azure Functions blade and it crashes a browser page.)

[MikeStall]

@ebashmakov - 929 was recently pushed to production - but you may need to restart the site for it to take affect.

[MikeStall]

After investigating this, I conclude we need to split out this into 2 APIs: list all function definitions, get stats for a specific function. We tried to shim the behavior into the existing dashboard API , but that doesn't work.

[MikeStall]

1. We'll add a new flag to /definitions to suppress the fan out.
2. Portal can pass the flag and use the existing "api/functions/invocations/{functionId}/timeline" to get those stats.

Portal changes are tracked via:
https://github.com/projectkudu/AzureFunctionsPortal/issues/844