dotnet / sign

Code Signing CLI tool supporting Authenticode, NuGet, VSIX, and ClickOnce
MIT License
447 stars 84 forks source link

Starting with version 0.9.1-beta.24123.2 error on tempfile/folder #684

Open RonKoppelaar opened 1 month ago

RonKoppelaar commented 1 month ago

Describe the bug Starting with version 0.9.1-beta.24123.2 I got file in use errors when using the sign tool. Its depending on machine type/configuration but unclear why. I have two build machines both run on W2019

Repro steps Run Sign.exe for one app file (Business Central) using certificate from Azure keyvault. Invoke the cmd from PS ISE.

        . $signingToolExe code azure-key-vault `
            --azure-key-vault-url "https://$KeyVaultName.vault.azure.net/" `
            --azure-key-vault-certificate $CertificateName `
            --azure-key-vault-client-id $ClientId `
            --azure-key-vault-client-secret (Get-SecretValue $ClientSecret) `
            --azure-key-vault-tenant-id $TenantId `
            --description $Description `
            --description-url $DescriptionUrl `
            --file-digest $DigestAlgorithm `
            --timestamp-digest $DigestAlgorithm `
            --timestamp-url $TimestampService `
            --verbosity $Verbosity `
            $FileToSign

Error stack:

VERBOSE: Running Invoke-cdsaALAppSign. PSBoundParameters: KeyVaultName:CodeSignERP CertificateName:CodeSignCertificate FilesToSign:C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app Description:test signing DescriptionUrl:https:\www.zig.nl Verbose:True Verbosity:Information VERBOSE: Start find sign tool VERBOSE: Instal Sign tool VERBOSE: Installing signing tool version 0.9.1-beta.24123.2 in C:\Users\BUILDA~1.JVF\AppData\Local\Temp\1\SigningTool-0.9.1-beta.24123.2 VERBOSE: Getting sign tool C:\Users\BUILDA~1.JVF\AppData\Local\Temp\1\SigningTool-0.9.1-beta.24123.2\Sign.exe VERBOSE: Using sign tool: C:\Users\BUILDA~1.JVF\AppData\Local\Temp\1\SigningTool-0.9.1-beta.24123.2\Sign.exe VERBOSE: Signing file: C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app info: Sign.Core.ISigner[0] Submitting C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app for signing. info: Sign.Core.ISigner[0] SignAsync called for C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app. Using C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app locally. info: Sign.Core.ISignatureProvider[0] Signing SignTool job with 1 files. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2146762749. info: Sign.Core.ISignatureProvider[0] Performing attempt #2 of 3 attempts after 5 s. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2147024864. info: Sign.Core.ISignatureProvider[0] Performing attempt #3 of 3 attempts after 11.1803398 s. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2147024864. fail: Sign.Core.ISignatureProvider[0] Failed to sign. Attempts exceeded. warn: Sign.Core.IDirectoryService[0] An exception occurred while attempting to delete directory C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib. System.IO.IOException: The process cannot access the file '5sdgrzsb.app' because it is being used by another process. at System.IO.FileSystem.RemoveDirectoryRecursive(String fullPath, WIN32_FINDDATA& findData, Boolean topLevel) at System.IO.FileSystem.RemoveDirectory(String fullPath, Boolean recursive) at System.IO.DirectoryInfo.Delete(Boolean recursive) at Sign.Core.DirectoryService.Delete(DirectoryInfo directory) in //src/Sign.Core/FileSystem/DirectoryService.cs:line 52 fail: Sign.Core.ISigner[0] Could not sign C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app. System.Exception: Could not sign C:\Users\buildadmin.jvfbbmhpxp7u6\AppData\Local\Temp\1\0zx1bmjk.5ib\5sdgrzsb.app. at Sign.Core.AzureSignToolSignatureProvider.<>cDisplayClass7_0.<b_0>d.MoveNext() in //src/Sign.Core/SignatureProviders/AzureSignToolSignatureProvider.cs:line 110 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.AzureSignToolSignatureProvider.SignAsync(IEnumerable1 files, SignOptions options) in //src/Sign.Core/SignatureProviders/AzureSignToolSignatureProvider.cs:line 104 at Sign.Core.AggregatingSignatureProvider.SignAsync(IEnumerable`1 files, SignOptions options) in //src/Sign.Core/SignatureProviders/AggregatingSignatureProvider.cs:line 204 at Sign.Core.Signer.<>cDisplayClass3_0.<b_0>d.MoveNext() in //src/Sign.Core/Signer.cs:line 153 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.Signer.SignAsync(IReadOnlyList1 inputFiles, String outputFile, FileInfo fileList, DirectoryInfo baseDirectory, String applicationName, String publisherName, String description, Uri descriptionUrl, Uri timestampU rl, Int32 maxConcurrency, HashAlgorithmName fileHashAlgorithm, HashAlgorithmName timestampHashAlgorithm) in /_/src/Sign.Core/Signer.cs:line 85 VERBOSE: Finished Invoke-cdsaALAppSign.

RonKoppelaar commented 1 month ago

I just created a brand new W22 machine in Azure but there I have the same issue

VERBOSE: Running Invoke-cdsaALAppSign. PSBoundParameters: KeyVaultName:CodeSignERP CertificateName:CodeSignCertificate FilesToSign:C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app Description:test signing DescriptionUrl:http s:\www.zig.nl Verbose:True Verbosity:debug SignToolVersion:0.9.1-beta.24170.3 VERBOSE: Start find sign tool version: 0.9.1-beta.24170.3 VERBOSE: Instal Sign tool VERBOSE: Installing signing tool version 0.9.1-beta.24170.3 in C:\Users\vmadmin\AppData\Local\Temp\2\SigningTool-0.9.1-beta.24170.3 VERBOSE: Getting sign tool C:\Users\vmadmin\AppData\Local\Temp\2\SigningTool-0.9.1-beta.24170.3\Sign.exe VERBOSE: Using sign tool: C:\Users\vmadmin\AppData\Local\Temp\2\SigningTool-0.9.1-beta.24170.3\Sign.exe VERBOSE: Signing file: C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app info: Sign.Core.ISigner[0] Submitting C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app for signing. info: Sign.Core.ISigner[0] SignAsync called for C:\temp\Zig_Zig365 Insights Connector_23.23.0.0.app. Using C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app locally. info: Sign.Core.ISignatureProvider[0] Signing SignTool job with 1 files. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2146762749. info: Sign.Core.ISignatureProvider[0] Performing attempt #2 of 3 attempts after 5 s. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2147024864. info: Sign.Core.ISignatureProvider[0] Performing attempt #3 of 3 attempts after 11.1803398 s. info: Sign.Core.ISignatureProvider[0] Signing C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app. fail: Sign.Core.ISignatureProvider[0] Signing failed with error -2147024864. fail: Sign.Core.ISignatureProvider[0] Failed to sign. Attempts exceeded. warn: Sign.Core.IDirectoryService[0] An exception occurred while attempting to delete directory C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs. System.IO.IOException: The process cannot access the file 'acnxoqlw.app' because it is being used by another process. at System.IO.FileSystem.RemoveDirectoryRecursive(String fullPath, WIN32_FINDDATA& findData, Boolean topLevel) at System.IO.FileSystem.RemoveDirectory(String fullPath, Boolean recursive) at System.IO.DirectoryInfo.Delete(Boolean recursive) at Sign.Core.DirectoryService.Delete(DirectoryInfo directory) in //src/Sign.Core/FileSystem/DirectoryService.cs:line 52 fail: Sign.Core.ISigner[0] Could not sign C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app. System.Exception: Could not sign C:\Users\vmadmin\AppData\Local\Temp\2\z3xw45h1.hzs\acnxoqlw.app. at Sign.Core.AzureSignToolSignatureProvider.<>cDisplayClass7_0.<b_0>d.MoveNext() in //src/Sign.Core/SignatureProviders/AzureSignToolSignatureProvi der.cs:line 110 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.AzureSignToolSignatureProvider.SignAsync(IEnumerable1 files, SignOptions options) in //src/Sign.Core/SignatureProviders/AzureSignToolSignatureProv ider.cs:line 104 at Sign.Core.AggregatingSignatureProvider.SignAsync(IEnumerable`1 files, SignOptions options) in //src/Sign.Core/SignatureProviders/AggregatingSignatureProvider .cs:line 204 at Sign.Core.Signer.<>cDisplayClass3_0.<b_0>d.MoveNext() in //src/Sign.Core/Signer.cs:line 156 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.Signer.SignAsync(IReadOnlyList1 inputFiles, String outputFile, FileInfo fileList, DirectoryInfo baseDirectory, String applicationName, String publi sherName, String description, Uri descriptionUrl, Uri timestampUrl, Int32 maxConcurrency, HashAlgorithmName fileHashAlgorithm, HashAlgorithmName timestampHashAlgorithm) i n /_/src/Sign.Core/Signer.cs:line 85 VERBOSE: Finished Invoke-cdsaALAppSign.

I'm kind of out of options as the previous versions don't Sign buisness central apps.

dtivel commented 1 month ago

@RonKoppelaar, thanks for the report. Sorry you're having this problem.

@clairernovotny had an idea that there might be contention with an antivirus/malware scanner. Are you using a stock VM template? If yes, which one is it?

Do you see a pattern in reproducibility (e.g.: it happens every time) or is it random?

Can you share a simplified repro that doesn't have any sensitive or proprietary data?

RonKoppelaar commented 1 month ago

Well I did disabled AV, in this case Windows defender by uninstalling the feature. This had no affect, It happens on all my build machines accept for one. It was lacking behind with some windows updates.

So I created a brand new environment W22 based on Azure Template: image

Where I can repro the issue consistantly...

After deploy of the server I manually installed .Net 8 SDK latest version

RonKoppelaar commented 1 month ago

Unfortune sharing repro without sensitive is not possible as the certificate is taken from AZ Key Vault. I could however share the script without any secrets though. Will add repro to this thread tomorrow.

XGWSBOE commented 1 month ago

@RonKoppelaar, thanks for the report. Sorry you're having this problem.

@clairernovotny had an idea that there might be contention with an antivirus/malware scanner. Are you using a stock VM template? If yes, which one is it?

Do you see a pattern in reproducibility (e.g.: it happens every time) or is it random?

Can you share a simplified repro that doesn't have any sensitive or proprietary data?

Hi, is there any news? because i have the same problem and i need a solution. on my local machine it works perfectly but on my vm it does not. maybe you have a vm image or an arm template for a working azure vm.

svengrav commented 1 month ago

I did some tests with an plain Azure VM (image: 2022-datacenter-azure-edition, size: Standard_D2s_v5), found an solution and have noticed the following:

First Attempt: After deploying the VM I manually installed dotnet using the 8.0 installer (https://dotnet.microsoft.com/en-us/download/dotnet/8.0) v.8.0.300 and ran this script:

dotnet tool install sign --global --prerelease

"Write-Host 'test'" | Out-File "c:\sign.ps1"
sign code azure-key-vault -kvu "https://....vault.azure.net/" `
    -kvc "..." `
    -kvi "..." `
    -kvs "" `
    -kvt "..." `
    --verbosity Debug `
    --description "..." `
    --description-url "https://.../" `
    --publisher-name "...." `
    "c:\sign.ps1"

info: Sign.Core.ISigner[0]
      Submitting c:\sign.ps1 for signing.
info: Sign.Core.ISigner[0]
      SignAsync called for c:\sign.ps1. Using C:\Users\azadmin\AppData\Local\Temp\prim4gnk.vvb\jr00srcb.ps1 locally.
info: Sign.Core.ISignatureProvider[0]
      Signing SignTool job with 1 files.
info: Sign.Core.ISignatureProvider[0]
      Signing C:\Users\azadmin\AppData\Local\Temp\prim4gnk.vvb\jr00srcb.ps1.
fail: Sign.Core.ISignatureProvider[0]
      Signing failed with error -2146881271.
info: Sign.Core.ISignatureProvider[0]
      Performing attempt #2 of 3 attempts after 5 s.
info: Sign.Core.ISignatureProvider[0]
      Signing C:\Users\azadmin\AppData\Local\Temp\prim4gnk.vvb\jr00srcb.ps1.
fail: Sign.Core.ISignatureProvider[0]
      Signing failed with error -2146881271.
info: Sign.Core.ISignatureProvider[0]
      Performing attempt #3 of 3 attempts after 11.1803398 s.

As shown, this resulted in an error and signing not worked.

Second Attempt: I redeployed the VM and installed dotnet using the script from Microsoft: https://dotnet.microsoft.com/download/dotnet/scripts/v1/dotnet-install.ps1 This resulted in the same error as above.

Third Attempt: I redeployed the VM and used Chocolatey with this script:

Set-ExecutionPolicy Bypass -Scope Process -Force; [System.Net.ServicePointManager]::SecurityProtocol = [System.Net.ServicePointManager]::SecurityProtocol -bor 3072; iex ((New-Object System.Net.WebClient).DownloadString('https://community.chocolatey.org/install.ps1'))
choco install dotnet-8.0-sdk -y

dotnet nuget add source https://api.nuget.org/v3/index.json -n nuget.org

dotnet tool install sign --global --prerelease

Invoke-Command -Session (New-PSSession) { 
  "Write-Host X" | Out-File "c:\sign.ps1"
  sign code azure-key-vault -kvu "https://....vault.azure.net/" `
      -kvc "..." `
      -kvi "..." `
      -kvs "" `
      -kvt "..." `
      --verbosity Debug `
      --description "..." `
      --description-url "https://.../" `
      --publisher-name "...." `
      "c:\sign.ps1"
  }

@dtivel Using this script, the signing was successful. It appears that Chocolatey installs some additional assets required by the sign tool.

RonKoppelaar commented 1 month ago

Thx for the investigation. That would explain only one of our buildserver did work. I expect its one of the older servers which in the past was created by automation, and using Chocolaty to install some assets

So main question is, altough there's a workaround installing assets what is the rootcause? Do you consider this to be an issue for the sign tool or should this be addressed to the .Net team?

XGWSBOE commented 1 month ago

@RonKoppelaar I believe the Sign app should identify any missing components and then determine whether they should be included with .NET or added as a new dependency.