Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue when using latest Microsoft.NET.Sdk.Functions (1.0.19) #3345

Open
johlrich opened this issue Aug 30, 2018 · 32 comments
Open

Issue when using latest Microsoft.NET.Sdk.Functions (1.0.19) #3345

johlrich opened this issue Aug 30, 2018 · 32 comments

Comments

@johlrich
Copy link
Contributor

@johlrich johlrich commented Aug 30, 2018

Description

Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator is a new package referenced by Microsoft.NET.Sdk.Functions and looks like it is responsible for generating an extensions.json file needed by the runtime.

When restoring packages with the latest paket and azure functions build, there are warnings MSB4011 at build time. When the build finishes the extensions.json generated is in the wrong location and empty.

Looking in the props/target files you do see a reference to both.

Full warning MSB4011 text:
C:\Users\JonathanOhlrich\.nuget\packages\microsoft.net.sdk.functions\1.0.19\build\netstandard1.0\Microsoft.NET.Sdk.Functions.props(38,3): warning MSB4011: "C:\Users\JonathanOhlrich\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.0\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.props" cannot be imported again. It was already imported at "C:\dev\authorization-service\src\Functions\obj\Functions.fsproj.nuget.g.props (17,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\dev\authorization-service\src\Functions\Functions.fsproj]
C:\Users\JonathanOhlrich\.nuget\packages\microsoft.net.sdk.functions\1.0.19\build\netstandard1.0\Microsoft.NET.Sdk.Functions.targets(45,3): warning MSB4011: "C:\Users\JonathanOhlrich\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.0\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.targets" cannot be imported again. It was already imported at "C:\dev\authorization-service\src\Functions\obj\Functions.fsproj.nuget.g.targets (9,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\dev\authorization-service\src\Functions\Functions.fsproj]

Repro steps

Paket version 5.176.9

Reference Microsoft.NET.Sdk.Functions 1.0.19 and then build

Expected behavior

Since Microsoft.NET.Sdk.Functions references Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator I suppose only Microsoft.NET.Sdk.Functions's props/targets should be used? I'm not positive how exactly both are being referenced

Actual behavior

Both exist causing warnings and incorrect behavior

Known workarounds

If you restore and manually remove the Imports lines referencing the Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator's target and props in the obj folder, then build --no-restore will succeed without warning and generate the extensions.json in the function app's bin folder

I tried to explicitly exclude the targets via Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator import_targets: false at both the paket.reference and paket.dependencies, but it would still appear.

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich
Copy link
Contributor Author

@johlrich johlrich commented Aug 30, 2018

Here's a repro zip, I left my attempt at working around it with import_targets: false
paket-3345.zip

With the warning you'll get an empty extensions.json file in bin\Debug\netstandard2.0 and with the workaround applied (removing ExtensionsMetadataGenerator imports from obj\paket-3345.fsproj.nuget.g.props and .target then build --no-restore) you'll see the two extensions referenced in the extensions.json file located in bin\Debug\netstandard2.0\bin

I'd be happy to open something upstream and follow up but I'm not sure what I would report to them yet as the same scenario works via nuget + vs. Here is the commit for the Function's sdk that added the reference / Import's, which seems to explain what's happening, but I'm not sure what necessarily should be happening yet: Azure/azure-functions-vs-build-sdk@ade32fd#diff-03102f2d5679fbdea7c914beee32b2b5

filled out extensions.json file example
{
  "extensions":[
    { "name": "DurableTask", "typeName":"Microsoft.Azure.WebJobs.Extensions.DurableTask.DurableTaskWebJobsStartup, Microsoft.Azure.WebJobs.Extensions.DurableTask, Version=1.6.0.0, Culture=neutral, PublicKeyToken=null"},
    { "name": "AzureStorage", "typeName":"Microsoft.Azure.WebJobs.Extensions.Storage.AzureStorageWebJobsStartup, Microsoft.Azure.WebJobs.Extensions.Storage, Version=3.0.0.0, Culture=neutral, PublicKeyToken=null"}
  ]
}
@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@soninaren @fabiocav I think this is a bug in azure functions sdk

forki added a commit to forki/azure-functions-vs-build-sdk that referenced this issue Aug 30, 2018
This import should be done via nuget/paket - see fsprojects/Paket#3345
@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich any ideas what that extensions file is about?

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich the really weird thing here is that we actually don't touch the .fsproj.nuget.g.props and .fsproj.nuget.g.targets - these are generated by nuget itself. That's why that proposed workaround doesn't work.

@johlrich
Copy link
Contributor Author

@johlrich johlrich commented Aug 30, 2018

@forki I haven't poked around enough to see exactly how it's used, but it's def used by the runtime to decide which extensions to load. When I loaded the app with the empty extensions file almost all of my bindings reported errors at func start, which led me to try it via VS and see the difference in output.

If I was a betting man I'm guessing it helps cold starts by pushing the reflection to decide what to load to these build tasks instead of at startup.

@johlrich
Copy link
Contributor Author

@johlrich johlrich commented Aug 30, 2018

BTW I don't know how you get your runtimes, but the npm package seems to lag behind, the tooling feed seems to get runtime zips added pretty quickly though. In case you need the latest as you explore the new version, check out the tooling feed repo: Azure/azure-functions-tooling-feed@b86d343

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich in your vanilla nuget test - you didn't add the package as direct dependency, right? You only referenced it via nuget's transitive dev mechanism. So I assume you can repro with vanilla nuget if you directly reference that new package in the fsproj. Can you please test that?

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich
Copy link
Contributor Author

@johlrich johlrich commented Aug 30, 2018

@forki Your hunch must be right; I was able to confirm via the nuget repro. Everything is fine with only Microsoft.NET.Sdk.Functions directly referenced. When I add the direct reference to Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator and run dotnet restore / build, you start seeing the same issue there too.

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

thanks for confirmation. working on temporary fix in paket which mitigates this

@matthid
Copy link
Member

@matthid matthid commented Aug 30, 2018

b) I know how to do temporary workaround

oO sounds quite dangerous to me

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@matthid well I need it to continue to work - business depends on it ....

forki added a commit that referenced this issue Aug 30, 2018
@matthid
Copy link
Member

@matthid matthid commented Aug 30, 2018

Why is that happening now and is so critical?

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

because they are deploying breaking changes in the runtime and we need to update our code to behave to that. see Azure/app-service-announcements#129

@forki
Copy link
Member

@forki forki commented Aug 30, 2018

@johlrich put "version 5.177.1" on top of your deps file, delete all /obj, run paket update and it should work

@johlrich
Copy link
Contributor Author

@johlrich johlrich commented Aug 30, 2018

Confirmed working here, thanks!

@johlrich johlrich closed this Aug 30, 2018
@forki
Copy link
Member

@forki forki commented Aug 30, 2018

I'd like to keep this open until it's fixed in azure functions and when we removed the workaround again

@forki forki reopened this Aug 30, 2018
@forki
Copy link
Member

@forki forki commented Aug 30, 2018

So if I read the example code at #3345 (comment) correctly then extensions.json is basically azure functions own version of binding redirects but for dotnet core. Am I correct? I mean after Microsoft people insisting that binding redirects are no longer needed for 3 years - how can this be?

@ravicini
Copy link

@ravicini ravicini commented Jan 28, 2019

@johlrich @forki
I can't get azure functions to work with paket and the v2 function runtime.
The runtime extensions json does not get written when building from Visual Studio (dotnet) works.

  • Microsoft.NET.Sdk.Functions 1.0.24.
  • paket 5.195.7

(see referenced issue above)
Does your solution work or do you have any hints?

@forki
Copy link
Member

@forki forki commented Jan 28, 2019

functions work fine for me. don't think there is anything special in paket here

@ravicini
Copy link

@ravicini ravicini commented Jan 28, 2019

I can reproduce the error with the attached Solutions:
Paket.Functions.zip

Steps to reproduce

  • Open the solution in visual studio
  • execute dotnet build in console, start function in visual studio with start with debugger -> works as intended
  • clean in VS, rebuild in VS -> start in VS -> stop executing as the extensions.json is not generated anymore (maybe needs a few clean/rebuilds)

On the nuget solution I am not able to reproduce the same error.
Nuget.Functions.zip

Sadly I could not find the reason for that behaviour yet.

@forki
Copy link
Member

@forki forki commented Jan 28, 2019

mhm. it does create the extensions.json for me on your sample

@ravicini
Copy link

@ravicini ravicini commented Jan 28, 2019

Oh, thanks for trying. This does not simplify the bug hunt.

I tried it again on a different environment/pc and the first build it generates the extensions.json.
After a clean/rebuild the extension.json does not longer gets generated.

@forki
Copy link
Member

@forki forki commented Jan 28, 2019

even after multiple Clean/Rebuild cycles. It's always there for me

@soninaren
Copy link

@soninaren soninaren commented Jan 28, 2019

@ravicini binary logger might help narrow down the issue.

@ravicini
Copy link

@ravicini ravicini commented Jan 28, 2019

@forki just evalutated the diagnostics log and it seems the file is always there for me too. The difference of the build is the content of the file. In VS it's empty, when building with dotnet the extensions are available.

@soninaren Are you referencing to http://www.msbuildlog.com/ ?

@ravicini
Copy link

@ravicini ravicini commented Jan 29, 2019

I analyzed the diagnostics log output and there are some differences which seems relevant to my bug.

Order of msbuild task execution:

  • Nuget version:
    _GenerateFunctionsPostBuild -> _GenerateFunctionsExtensionsMetadataPostBuild
  • Paket version:
    _GenerateFunctionsExtensionsMetadataPostBuild -> _GenerateFunctionsPostBuild

Paths used in _GenerateFunctionsExtensionsMetadataPostBuild task:

  • Paket version:
1>Target "_GenerateFunctionsExtensionsMetadataPostBuild" in file "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.targets":
1>  Using "GenerateFunctionsExtensionsMetadata" task from assembly "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\..\tools\net46\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.dll".
1>  Task "GenerateFunctionsExtensionsMetadata"
1>    Task Parameter:SourcePath=C:\workspace\Paket.Functions\Paket.Functions\bin\Debug\netcoreapp2.2\
1>    Task Parameter:OutputPath=C:\workspace\Paket.Functions\Paket.Functions\bin\Debug\netcoreapp2.2\
1>  Done executing task "GenerateFunctionsExtensionsMetadata".
1>  Task "Move" skipped, due to false condition; ($(_IsFunctionsSdkBuild) == 'true' AND Exists('$(TargetDir)extensions.json')) was evaluated as ( == 'true' AND Exists('C:\workspace\Paket.Functions\Paket.Functions\bin\Debug\netcoreapp2.2\extensions.json')).
1>Done building target "_GenerateFunctionsExtensionsMetadataPostBuild" in project "Paket.Functions.csproj".
  • Nuget version:
1>Target "_GenerateFunctionsExtensionsMetadataPostBuild" in file "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.targets":
1>  Using "GenerateFunctionsExtensionsMetadata" task from assembly "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\..\tools\net46\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.dll".
1>  Task "GenerateFunctionsExtensionsMetadata"
1>    Task Parameter:SourcePath=C:\workspace\Nuget.Functions\Nuget.Functions\bin\Debug\netcoreapp2.2\bin
1>    Task Parameter:OutputPath=C:\workspace\Nuget.Functions\Nuget.Functions\bin\Debug\netcoreapp2.2\bin
1>  Done executing task "GenerateFunctionsExtensionsMetadata".
1>  Task "Move" skipped, due to false condition; ($(_IsFunctionsSdkBuild) == 'true' AND Exists('$(TargetDir)extensions.json')) was evaluated as (true == 'true' AND Exists('C:\workspace\Nuget.Functions\Nuget.Functions\bin\Debug\netcoreapp2.2\extensions.json')).
1>Done building target "_GenerateFunctionsExtensionsMetadataPostBuild" in project "Nuget.Functions.csproj".

2 Warnings in Paket version:

1>C:\Users\marco.ravicini\.nuget\packages\microsoft.net.sdk.functions\1.0.24\build\netstandard1.0\Microsoft.NET.Sdk.Functions.props(38,3): warning MSB4011: "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.props" cannot be imported again. It was already imported at "C:\workspace\Paket.Functions\Paket.Functions\obj\Paket.Functions.csproj.nuget.g.props (17,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\workspace\Paket.Functions\Paket.Functions\Paket.Functions.csproj]
1>C:\Users\marco.ravicini\.nuget\packages\microsoft.net.sdk.functions\1.0.24\build\netstandard1.0\Microsoft.NET.Sdk.Functions.targets(45,3): warning MSB4011: "C:\Users\marco.ravicini\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.1\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.targets" cannot be imported again. It was already imported at "C:\workspace\Paket.Functions\Paket.Functions\obj\Paket.Functions.csproj.nuget.g.targets (9,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\workspace\Paket.Functions\Paket.Functions\Paket.Functions.csproj]

When I clean everything and build it works, rebuild initializes the error

See the following diagnostics log for differences:
paket-initial-build.log
paket-rebuild.log

Based on this I have a few assumptions:

  • Order of execution matters
  • Warnings led to "different" order of execution
  • Paths used in execution rely on order of execution

@soninaren or @fabiocav could you support me from the azure-functions-vs-build-sdk side on this issue?

To complete the analysis here is the nuget log:
nuget-msbuild.log

@forki
Copy link
Member

@forki forki commented Apr 4, 2019

we don't explicitly use those targets.

we use:

BeforeTargets="_GenerateDotnetCliToolReferenceSpecs;_GenerateProjectRestoreGraphPerFramework;_GenerateRestoreGraphWalkPerFramework;CollectPackageReferences"
@jbeeko
Copy link
Contributor

@jbeeko jbeeko commented Apr 4, 2019

This still seems to occur but only when using VisualStudio. With VS 2019 & Paket version 5.200.4 building a functions v2 project with the netcoreapp2.2 framework results in the symptoms described. VisualStudio gives the warnings:

1>C:\Users\jbeeko\.nuget\packages\microsoft.net.sdk.functions\1.0.26\build\netstandard1.0\Microsoft.NET.Sdk.Functions.props(38,3): warning MSB4011: "C:\Users\jbeeko\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.2\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.props" cannot be imported again. It was already imported at "C:\Users\jbeeko\Documents\GitHub\function-publish-error\src\Seymour.Api\obj\Seymour.Api.fsproj.nuget.g.props (17,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\Users\jbeeko\Documents\GitHub\function-publish-error\src\Seymour.Api\Seymour.Api.fsproj]
1>C:\Users\jbeeko\.nuget\packages\microsoft.net.sdk.functions\1.0.26\build\netstandard1.0\Microsoft.NET.Sdk.Functions.targets(60,3): warning MSB4011: "C:\Users\jbeeko\.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator\1.0.2\build\Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator.targets" cannot be imported again. It was already imported at "C:\Users\jbeeko\Documents\GitHub\function-publish-error\src\Seymour.Api\obj\Seymour.Api.fsproj.nuget.g.targets (9,5)". This is most likely a build authoring error. This subsequent import will be ignored. [C:\Users\jbeeko\Documents\GitHub\function-publish-error\src\Seymour.Api\Seymour.Api.fsproj]

plus the nuget.g.props and nuget.g.targets files have a reference to the ExtensionsMetadataGenerator.targets and the bin\debbug\netcoreapp2.2 directory contains an empty extensions.json file.

Using dotnet restore & build does not result in those warnings and gives artifacts that can be run with the Azure Functions cli tools. A repository that reproduces this on VS is here: https://github.com/transactiveltd/function-publish-error

@LightosTomJ
Copy link

@LightosTomJ LightosTomJ commented May 21, 2019

This may be be irrelevant, however I tried to add an "interface" class within my Function Apps project, this triggered the issue referenced above. I looked through windows explorer for "C:\Users\WhatEverYourNameIs.nuget\packages\microsoft.azure.webjobs.script.extensionsmetadatagenerator", which showed a version "1.0.0 (beta)".

I searched for a specific "microsoft.azure.webjobs.script.extensionsmetadatagenerator" NuGet package, and found a "1.1.1" version. I included this, which resolved the issue for me.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
7 participants