Azure/azure-functions-powershell-worker

Azure Function fails with "EXCEPTION: Failed to install package: sign 0.9.1-beta.24469.1"

thomaseyde opened this issue · 12 comments

Azure Function, written in Python, fails with:

EXCEPTION: Failed to install package: sign 0.9.1-beta.24469.1

It is uncertain when the function started to fail. The function app is simple:

PSFunctionApp/host.json:

{
  "version": "2.0",
  "managedDependency": {
    "Enabled": true
  },
  "extensionBundle": {
    "id": "Microsoft.Azure.Functions.ExtensionBundle",
    "version": "[4.*, 5.0.0)"
  }
}

PSFunctionApp/requirements.psd1:

@{
    'TrustedSigning' = '0.*'
}

PSFunctionApp/SignPowerShell/run.ps1:

# ...

$params = @{
    Endpoint = "https://weu.codesigning.azure.net/"
    CodeSigningAccountName = "..."
    CertificateProfileName = "..."
    Files = "..."
    FileDigest = "SHA256"
    TimestampRfc3161 = "http://timestamp.acs.microsoft.com"
    TimestampDigest = "SHA256"
}

Invoke-TrustedSigning @params

# ...

Stack trace:

Exception: Failed to install package: sign 0.9.1-beta.24469.1
Stack:    at System.Management.Automation.Runspaces.PipelineBase.Invoke(IEnumerable input)
   at System.Management.Automation.PowerShell.Worker.ConstructPipelineAndDoWork(Runspace rs, Boolean performSyncInvoke)
   at System.Management.Automation.PowerShell.Worker.CreateRunspaceIfNeededAndDoWork(Runspace rsToUse, Boolean isSync)
   at System.Management.Automation.PowerShell.CoreInvokeHelper[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.CoreInvoke[TOutput](IEnumerable input, PSDataCollection`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.Invoke[T](IEnumerable input, IList`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.Invoke[T]()
   at Microsoft.Azure.Functions.PowerShellWorker.PowerShell.PowerShellExtensions.InvokeAndClearCommands[T](PowerShell pwsh)
   at Microsoft.Azure.Functions.PowerShellWorker.PowerShell.PowerShellManager.ExecuteUserCode(Boolean addPipelineOutput, IDictionary outputBindings)
   at Microsoft.Azure.Functions.PowerShellWorker.PowerShell.PowerShellManager.InvokeFunction(AzFunctionInfo functionInfo, Hashtable triggerMetadata, TraceContext traceContext, RetryContext retryContext, IList`1 inputData, FunctionInvocationPerformanceStopwatch stopwatch, OpenTelemetryInvocationContext otelContext)
   at Microsoft.Azure.Functions.PowerShellWorker.RequestProcessor.InvokeFunction(AzFunctionInfo functionInfo, PowerShellManager psManager, FunctionInvocationPerformanceStopwatch stopwatch, InvocationRequest invocationRequest)
   at Microsoft.Azure.Functions.PowerShellWorker.RequestProcessor.ProcessInvocationRequestImpl(StreamingMessage request, AzFunctionInfo functionInfo, PowerShellManager psManager, FunctionInvocationPerformanceStopwatch stopwatch)

Error log:

2025-02-14T07:52:57.171 [Information] Executing 'Functions.SignPowerShell' (Reason='This function was programmatically called via the host APIs.', Id=b1a3c408-8d66-43d6-a5c8-2673aa34249c)
2025-02-14T07:52:57.201 [Information] OUTPUT:
2025-02-14T07:52:57.201 [Information] OUTPUT:     Directory: C:\local\Temp
2025-02-14T07:52:57.201 [Information] OUTPUT:
2025-02-14T07:52:57.201 [Information] OUTPUT: Mode                 LastWriteTime         Length Name
2025-02-14T07:52:57.201 [Information] OUTPUT: ----                 -------------         ------ ----
2025-02-14T07:52:57.201 [Information] OUTPUT: d----           2/14/2025  7:52 AM                8b138bff-d0eb-4e00-8b83-192a705d5741
2025-02-14T07:52:57.202 [Information] INFORMATION: Checking for required dependencies.
2025-02-14T07:52:57.204 [Information] INFORMATION: 	Build tools package installed: True
2025-02-14T07:52:57.204 [Information] INFORMATION: 	Trusted signing package installed: True
2025-02-14T07:52:57.204 [Information] INFORMATION: 	Sign CLI package installed: False
2025-02-14T07:52:57.204 [Information] INFORMATION: 	Installing required dependencies.
2025-02-14T07:52:57.226 [Information] INFORMATION: 		Found existing package source: https://www.nuget.org/api/v2/
2025-02-14T07:52:57.226 [Information] INFORMATION: 		Installing package: sign 0.9.1-beta.24469.1
2025-02-14T07:52:57.449 [Error] EXCEPTION: Failed to install package: sign 0.9.1-beta.24469.1

Exception             : 
    Type                        : System.Management.Automation.RuntimeException
    ErrorRecord                 : 
        Exception             : 
            Type    : System.Management.Automation.ParentContainsErrorRecordException
            Message : Failed to install package: sign 0.9.1-beta.24469.1
            HResult : -2146233087
        CategoryInfo          : NotSpecified: (:) [], ParentContainsErrorRecordException
        FullyQualifiedErrorId : RuntimeException
    WasThrownFromThrowStatement : True
    Message                     : Failed to install package: sign 0.9.1-beta.24469.1
    HResult                     : -2146233087
TargetObject          : Failed to install package: sign 0.9.1-beta.24469.1
CategoryInfo          : OperationStopped: (Failed to install p… 0.9.1-beta.24469.1:String) [], RuntimeException
FullyQualifiedErrorId : Failed to install package: sign 0.9.1-beta.24469.1
InvocationInfo        : 
    ScriptLineNumber : 209
    OffsetInLine     : 17
    HistoryId        : 1
    ScriptName       : C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1
    Line             : throw "Failed to install package: $PackageName $PackageVersion"
                       
    Statement        : throw "Failed to install package: $PackageName $PackageVersion"
    PositionMessage  : At C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1:209 char:17
                       + …             throw "Failed to install package: $PackageName $PackageVe …
                       +               ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    PSScriptRoot     : C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall
    PSCommandPath    : C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1
    CommandOrigin    : Internal
ScriptStackTrace      : at Install-NugetToolPackage, C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1: line 209
                        at Get-EveryDependency, C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1: line 34
                        at Invoke-TrustedSigning, C:\home\data\ManagedDependencies\2501211436403182907.r\TrustedSigning\0.5.3\TrustedSigning.psm1: line 143
                        at <ScriptBlock>, C:\home\site\wwwroot\SignPowerShell\run.ps1: line 31

This is not an azure-functions-extension-bundles issue,

bundles don't have any dependency on sign package. Also, all bundles' dependencies are packaged with it.

It can be investigated by azure-functions-powershell-worker team

I'm also experiencing this issue using trusted signing in my electron project using https://www.electron.build/code-signing-win.html#using-azure-trusted-signing-beta which basically does Invoke-TrustedSigning. Seems to be introduced by the update on Feb 7 since it worked on Jan 24. Unfortunately, that's pretty critical, since we're not able to release new versions. Are there any workarounds?
Here the build output (redacted):

11:35:27    • verifying env vars for authenticating to Microsoft Entra ID
11:35:37    • Above command failed, retrying 3 more times
11:35:37    • Above command failed, retrying 3 more times
11:35:37    • Above command failed, retrying 3 more times
11:35:39    ⨯ Exit code: 1. Command failed: powershell.exe -NoProfile -NonInteractive -Command Invoke-TrustedSigning -Endpoint https://weu.codesigning.azure.net/ -CertificateProfileName PVSTrustedSigningProfile -CodeSigningAccountName PVSReissGmbH -TimestampRfc3161 http://timestamp.acs.microsoft.com/ -TimestampDigest SHA256 -FileDigest SHA256 -Files "e:\jenkins\workspace\......\release\win-ia32-unpacked\resources\app.exe"
11:35:39  Das Toolpaket konnte nicht wiederhergestellt werden.
11:35:39  Fehler bei der Installation des Tools "sign". Dieser Fehler kann folgende Ursachen haben:
11:35:39  
11:35:39  * Sie versuchen, eine Vorschauversion zu installieren und haben nicht die Option "--version" verwendet, um die Version anzugeben.
11:35:39  * Ein Paket mit diesem Namen wurde gefunden, aber es handelte sich nicht um ein .NET-Tool.
11:35:39  * Auf den erforderlichen NuGet-Feed kann nicht zugegriffen werden, m�glicherweise aufgrund eines Problems mit der Internetverbindung.
11:35:39  * Sie haben den Namen des Tools falsch eingegeben.
11:35:39  
11:35:39  Weitere Gr�nde sowie Informationen zum Erzwingen der Paketbenennung finden Sie unter https://aka.ms/failure-installing-tool.
11:35:39  Failed to install package: sign 0.9.1-beta.24469.1
11:35:39  In 
11:35:39  C:\Users\service_jenkins\Documents\WindowsPowerShell\Modules\TrustedSigning\0.5.3\NugetInstall\NugetInstall.psm1:209 
11:35:39  Zeichen:17
11:35:39  + ...             throw "Failed to install package: $PackageName $PackageVe ...
11:35:39  +                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
11:35:39      + CategoryInfo          : OperationStopped: (Failed to insta....1-beta.24469.1:String) [], RuntimeException
11:35:39      + FullyQualifiedErrorId : Failed to install package: sign 0.9.1-beta.24469.1
11:35:39

Invoking the the command manually gives:

Checking for required dependencies.
        Build tools package installed: True
        Trusted signing package installed: True
        Sign CLI package installed: False
        Installing required dependencies.
                Found existing package source: https://www.nuget.org/api/v2/
                Installing package: sign 0.9.1-beta.24469.1
Das Toolpaket konnte nicht wiederhergestellt werden.
Fehler bei der Installation des Tools "sign". Dieser Fehler kann folgende Ursachen haben:

* Sie versuchen, eine Vorschauversion zu installieren und haben nicht die Option "--version" verwendet, um die Version anzugeben.
* Ein Paket mit diesem Namen wurde gefunden, aber es handelte sich nicht um ein .NET-Tool.
* Auf den erforderlichen NuGet-Feed kann nicht zugegriffen werden, möglicherweise aufgrund eines Problems mit der Internetverbindung.
* Sie haben den Namen des Tools falsch eingegeben.

Weitere Gründe sowie Informationen zum Erzwingen der Paketbenennung finden Sie unter https://aka.ms/failure-installing-tool.
Failed to install package: sign 0.9.1-beta.24469.1
In C:\Users\service_jenkins\Documents\WindowsPowerShell\Modules\TrustedSigning\0.5.3\NugetIns
tall\NugetInstall.psm1:209 Zeichen:17
+ ...             throw "Failed to install package: $PackageName $PackageVe ...
+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : OperationStopped: (Failed to insta....1-beta.24469.1:String) [
   ], RuntimeException
    + FullyQualifiedErrorId : Failed to install package: sign 0.9.1-beta.24469.1

Hi @thomaseyde @gschafra ,
Based on the stack traces provided, it looks like the TrustedSigning module is trying to install some additional dependencies at runtime, specifically the NuGet dependency "sign 0.9.1-beta.24469.1".
The error messages also seem to indicate that NuGet is inaccessible to your app - have you confirmed that whatever environment you are running in is able to access NuGet.org?

The exception message only says "Failed to install package". I cannot see anything in there which hints to access failures.

According to the console in my function app, I have access to NuGet:

C:\home\site\wwwroot>tcpping nuget.org
Connected to nuget.org:80, time taken: 125ms
Connected to nuget.org:80, time taken: 93ms
Connected to nuget.org:80, time taken: 93ms
Connected to nuget.org:80, time taken: 93ms
Complete: 4/4 successful attempts (100%). Average success time: 101ms

The problem only occurs with TrustedSigning module version v0.5.3, wich in my case is installed by electron builder before invoking the signing (see https://github.com/electron-userland/electron-builder/pull/8833/files#diff-75a2e6ce65385a7da455ee9eca164f830e03ad15b58fefdd9c1e437a43642e3eR42). In this case the nuget sign package of version 0.9.1-beta.24469.1 is tried to be installed... which fails

Installing v0.5.3 works:

Image

... but invoking the signing command fails while installing required dependencies:

Image

Installing v0.5.0 works:

Image

...and the invoking the signing command with installed version v0.5.0 everything works like expected:

Image

O.k... my mistake... did not take updated requirements (.NET v8) for sign tool into account, see https://www.nuget.org/packages/sign/0.9.1-beta.24469.1#:~:text=in%20mainstream%20support-,.NET%208%20SDK%20or%20later,-Microsoft%20Visual%20C

Is the .NET 8 requirement the problem? If so, how can I control which .NET version my PowerShell function app is using?