Azure Function not loaded with specific host settings - logging #6660
Assignees
Labels
area-tooling
azure
Issues associated specifically with scenarios tied to using Azure
azure-functions
Issues related to the Azure Functions integration
vs
Issues related to Visual Studio tooling for aspire
Milestone
Comments
|
@petrkasnal Thanks for reporting this issue! I took at stab and trying your repro and noticed the following exception at startup: I believe this is related to the fact that the builder.AddAzureFunctionsProject<Projects.AzureFunctionsTest_Functions>("funcapp")
.WithReference(messaging)
.WithReference(messaging2)
.WithReference(messaging3)
.WithReference(messaging4)
.WithReference(messaging5)
.WithReference(messaging6);
//.WithReference(eventHubs);
//.WithReference(serviceBus);Once I re-enable the event hubs resource, things seem to work fine there. You also mentioned that you're seeing the following DCP exception: In the past, I've seen this happen when the functions process fails to start. This might be related to the issues you are seeing in #6661. Do you repro this when launching from the command line via |
captainsafia
added
area-integrations
|
I edited the repository. I left really just the function execution to show that it doesn't matter if something is attached to it.
If the Aspire starts, the function doesn't run. If a line is added to host.json as in the specification - I just tried using |
|
@petrkasnal Can you verify what version of the Azure Functions Core Tools you are using? Running: should get this info. |
|
@captainsafia sure - 4.0.5907 |
|
@petrkasnal Ah, I see. Your version is about 6 months old. Can you try upgrading to the latest? It should be 4.6610. |
|
@captainsafia I promoted the version. However, it didn't help, it's still the same.I tried running from visual studio and using dotnet run. |
|
If you get that DCP error it means your functions tooling or visual studio version is too old. Here's how you can force an update in VS https://learn.microsoft.com/en-us/dotnet/aspire/serverless/functions?tabs=dotnet-cli&pivots=visual-studio#azure-function-project-constraints |
|
@davidfowl I've tried that before. I use Visual Studio 2022 preview. And I have the latest version installed. |
|
Are you still seeing: ? |
|
@davidfowl
|
@davidfowl That doesn't always have to be the case. Sometimes the DCP timeout will happen if the Functions host failed to start for some other reason. From this comment, I noticed that @petrkasnal didn't have the correct @petrkasnal Can you share the logs you see out of the Functions project now that you've updated your Core tools? |
It really shouldn't though. This usually means there's some IDE issue interacting with the functions tooling. cc @karolz-ms |
|
@captainsafia
Yes sure here is the full Visual Studio log: Logs on startup: Nothing see in Aspire console protocols. Thank you |
|
@davidfowl |
|
@petrkasnal OK! I was able to get a repro of the issue and extracted logs from DCP to help debug this. @karelz will share more details on this later. Similar to the other issue you reported, this bug seems to manifest when launching from Visual Studio in particular. |
|
I took a look and it seems DCP is doing what it is supposed to do. It just is not receiving a response from Visual Studio when requesting the startup of the functions project. @captainsafia will follow up. This might be related to, or a duplicate of #6661 |
|
@karolz-ms do we know which command is taking long to respond? |
|
@davidfowl sorry this is outside of my area of expertise. My suspicion is that it is something specific to the VS-functions project interface, since I was able to run the app successfully from command line ( @tlmii FYI |
|
@karolz-ms I meant in the dcp logs. |
|
@davidfowl it was "start project" request from DCP |
|
@vijayrkn can you prioritize this one? |
|
@tlmii has been taking a look at this in the background. We've got a reliable repro and have narrowed down that this seems to specifically be related to the Azure Functions + VS + debugging. @tlmii has a hunch that the issue here might be related to the Functions runtime not writing some required debugging metadata to a shared source file when the debug log is enabled. @tlmii -- do you want to verify what you've learned here? |
|
Yeah, so to start off, we should be able to confirm that this is a debugging only scenario. It should work fine in VS for Ctrl+F5. When we start debugging a functions app, we need to know the secondary process ID that functions launches so that we can attach the debugger to it. Func.exe (or in this case really dotnet.exe func.dll) normally writes that information out to a temporary file using a startup hook (https://github.com/Azure/azure-functions-dotnet-worker/blob/c4113d1c5936ab3235d7a73ec5a88596977c8335/src/DotNetWorker.Core/StartupHook.cs#L60) and VS waits for that to be written and uses the information there to attach the debugger to the correct processes. For some reason, in this scenario, with "Default": "Debug", that information is never getting written to the output file and so VS ends up waiting (effectively) forever and you run into the timeout. I attempted to reproduce the behavior outside of VS by calling the same command line from the same working directly that we pass to the debugger but it did not reproduce the behavior, so I must have missed some piece of what the debugger is doing. The code in Azure Functions that writes out the PID to the output file (various methods in here: https://github.com/Azure/azure-functions-core-tools/blob/v4.x/src/Azure.Functions.Cli/Diagnostics/ColoredConsoleLogger.cs) uses fairly normal ILogger semantics, including having logging filtering involved. So it is possible that there is some conflict between that logging filtering and the configuration in host.json that is preventing it from being written out. That's just a guess though - would need someone from the Azure Functions team to confirm that. |
|
We have a bunch of existing node.js and python azure functions apps which we're looking to migrate to add into our .NET Aspire solution. What's the best way to achieve that? Add dockerfile to our azure functions and then import into .NET Aspire via .AddDockerfile() or .AddContainer() - but not sure if this allows communication over HTTP with others services in .NET aspire solution? I appreciate this thread might not be the best space for this query, but please pin out to the right resources if you know any way to achieve this 🙏 |
|
We believe we've tracked down the cause of the deadlock that is causing the original issue here. Essentially, nothing was reading from the console output of the host process while we waited for the worker process to launch. If there was enough output written (which was the case when logging was set to debug), the buffer would fill up and the last write attempt would be blocked, preventing the host process from eventually launching the worker process. Fix is in progress. |
|
@tlmii Sounds good! Thanks a lot |
|
Ignore that tag of a PR, that was for a different fix. We do have a fix for this issue that has been checked in and should be available with the next preview release of VS. Assuming validation goes well we can also discuss servicing 17.12 with it. |
|
@tlmii Hi, I would just like to ask when the patch might be released. Thank you very much. |
|
@petrkasnal It will be in the next preview release of VS 17.13 when that is released. No public date of that yet but it's not far off. I have not heard anything about servicing 17.12 at this point. |
davidfowl
removed
area-integrations
|
VS 17.13 Preview 4 was released last week. I've verified that the repro shared in the original post launches successfully on this version and I see Debug level logs. Closing as fixed. If you run into any issues, feel free to file a new bug. |
Tested and working. Thanks a lot. Great work. |
1 task
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Is there an existing issue for this?
Describe the bug
When I use the Azure Function in Aspire, a strange behavior occurs when I have this block in host.json. It happened in the previous version 9.0 as I mention here and it happens now in version 9.1.0-preview.1.24561.5.
What happens is that Aspire starts and shows the function loading, which eventually doesn't load and after 120 seconds it throws Failed to start. I used the example repository for Azure Function in Aspire.
I prepared repository - https://github.com/petrkasnal/AspireHostProblem
Expected Behavior
I would expect the logging settings to have no effect on Azure function execution. It's holding us back now because I have to keep overwriting it and that's not very convenient.
Steps To Reproduce
Open repository - https://github.com/petrkasnal/AspireHostProblem
Run AzureFunctionsTest.AppHost project
If you edit host.json - comment line "Default": "Debug" and starts work
Exceptions (if any)
No response
.NET Version info
9.0.0-rc.2.24473.5
Anything else?
No response
The text was updated successfully, but these errors were encountered: