sign icon indicating copy to clipboard operation
sign copied to clipboard

Published 20 hours ago • verified publisher icon dotnet

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

Open RonKoppelaar opened this issue 9 months ago • 8 comments

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_FIND_DATA& 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.<>c__DisplayClass7_0.<<SignAsync>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.<>c__531.<<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(IEnumerable1 files, SignOptions options) in /_/src/Sign.Core/SignatureProviders/AggregatingSignatureProvider.cs:line 204 at Sign.Core.Signer.<>c__DisplayClass3_0.<<SignAsync>b__0>d.MoveNext() in /_/src/Sign.Core/Signer.cs:line 153 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c__531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.Signer.SignAsync(IReadOnlyList`1 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 avatar May 08 '24 09:05 RonKoppelaar

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_FIND_DATA& 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.<>c__DisplayClass7_0.<<SignAsync>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.<>c__531.<<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(IEnumerable1 files, SignOptions options) in /_/src/Sign.Core/SignatureProviders/AggregatingSignatureProvider .cs:line 204 at Sign.Core.Signer.<>c__DisplayClass3_0.<<SignAsync>b__0>d.MoveNext() in /_/src/Sign.Core/Signer.cs:line 156 --- End of stack trace from previous location --- at System.Threading.Tasks.Parallel.<>c__531.<<ForEachAsync>b__53_0>d.MoveNext() --- End of stack trace from previous location --- at Sign.Core.Signer.SignAsync(IReadOnlyList`1 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.

RonKoppelaar avatar May 10 '24 19:05 RonKoppelaar

@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?

dtivel avatar May 14 '24 18:05 dtivel

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 avatar May 14 '24 18:05 RonKoppelaar

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.

RonKoppelaar avatar May 14 '24 18:05 RonKoppelaar

@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.

XGWSBOE avatar May 23 '24 06:05 XGWSBOE

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.

svengrav avatar May 23 '24 07:05 svengrav

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?

RonKoppelaar avatar May 24 '24 07:05 RonKoppelaar

@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.

XGWSBOE avatar May 24 '24 09:05 XGWSBOE

After i installed the newest VCRedist (x64), it worked for me. Maybe this helps.

MJECloud avatar Aug 14 '24 06:08 MJECloud

Installing the Microsoft Visual C++ 14 runtime will resolve this.

We considered a few different solutions, including:

  • Bundle the Microsoft Visual C++14 runtime with Sign CLI. The runtime is serviceable, and by including our own copy in the Sign CLI package, we take ownership of servicing that copy. We do not want the burden of servicing ownership if we don't need to. Having the runtime installed separately as a prerequisite means it's available for Sign CLI to use, and it will be serviced through its normal update channels (e.g.: Visual Studio Installer, Windows Update). This is desirable.
  • Indicate that the Microsoft Visual C++14 runtime is a prerequisite. This is unusual for a .NET tool, but that's where we are now. Technically, the runtime is only a prerequisite if you want to sign .app files, and ideally, we could warn only when you were signing an .app file, but Sign CLI doesn't have a way (today) of identifying upfront want will be signed and what signing prerequisites exist (if any) for those files.

I created a PR (https://github.com/dotnet/sign/pull/762) to warn if MSVCRT 14 is not detected.

dtivel avatar Sep 17 '24 18:09 dtivel