sign icon indicating copy to clipboard operation
sign copied to clipboard

Sign Service error: Sign tool completed with error -2145844845

Open Thoorium opened this issue 3 years ago • 2 comments

I've deployed SignService as an Azure Website using the tools included with the project. The website works and I've successfully configured my user with an existing KeyVault. When I use the SignClient to sign my exe application (a simple default console application), the service fails to sign the executable with the error "Sign tool completed with error -2145844845".

I've tested the signing process using AzureSignTool locally, with the same key vault & certificate that are configured with SignService and it worked. Any idea what is going on?

Here's the log stream of a sign event:

2021-09-02 18:13:49.361 +00:00 [Information] Microsoft.AspNetCore.Hosting.Diagnostics: Request starting HTTP/1.1 POST https://<removed>.azurewebsites.net/sign?descriptionUrl=&description=&name=<removed>&hashMode=Sha256 multipart/form-data; boundary="----MyGreatBoundary" 126117
2021-09-02 18:13:50.163 +00:00 [Information] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler: Successfully validated the token.
2021-09-02 18:13:50.816 +00:00 [Information] Microsoft.AspNetCore.Authorization.DefaultAuthorizationService: Authorization was successful.
2021-09-02 18:13:50.817 +00:00 [Information] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executing endpoint 'SignService.Controllers.SignController.SignFile (SignService)'
2021-09-02 18:13:50.875 +00:00 [Information] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Route matched with {action = "SignFile", controller = "Sign", area = "", page = ""}. Executing controller action with signature System.Threading.Tasks.Task SignFile(Microsoft.AspNetCore.Http.IFormFile, Microsoft.AspNetCore.Http.IFormFile, SignService.SigningTools.HashMode, System.String, System.String, System.String) on controller SignService.Controllers.SignController (SignService).
2021-09-02 18:13:50.882 +00:00 [Information] Microsoft.AspNetCore.Authorization.DefaultAuthorizationService: Authorization was successful.
2021-09-02 18:13:51.086 +00:00 [Information] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executing action method SignService.Controllers.SignController.SignFile (SignService) - Validation state: Valid
2021-09-02 18:13:51.115 +00:00 [Information] SignService.Controllers.SignController: SignFile called for <removed>.exe. Using C:\local\Temp\b04q102l.p3s\cg2gsarj.exe locally.
2021-09-02 18:13:51.202 +00:00 [Information] SignService.AzureSignToolSignService: Signing SignTool job <removed> with 1 files
2021-09-02 18:13:51.737 +00:00 [Information] SignService.AzureSignToolSignService: Signing using C:\local\Temp\b04q102l.p3s\cg2gsarj.exe
2021-09-02 18:13:52.159 +00:00 [Error] SignService.AzureSignToolSignService: Sign tool completed with error -2145844845
2021-09-02 18:13:52.159 +00:00 [Information] SignService.AzureSignToolSignService: Performing attempt #2 of 3 attempts after 5s
2021-09-02 18:13:57.174 +00:00 [Information] SignService.AzureSignToolSignService: Signing using C:\local\Temp\b04q102l.p3s\cg2gsarj.exe
2021-09-02 18:13:57.294 +00:00 [Error] SignService.AzureSignToolSignService: Sign tool completed with error -2145844845
2021-09-02 18:13:57.294 +00:00 [Information] SignService.AzureSignToolSignService: Performing attempt #3 of 3 attempts after 11.1803398s
2021-09-02 18:14:08.477 +00:00 [Information] SignService.AzureSignToolSignService: Signing using C:\local\Temp\b04q102l.p3s\cg2gsarj.exe
2021-09-02 18:14:08.834 +00:00 [Error] SignService.AzureSignToolSignService: Sign tool completed with error -2145844845
2021-09-02 18:14:08.834 +00:00 [Error] SignService.AzureSignToolSignService: Failed to sign. Attempts exceeded
2021-09-02 18:14:08.982 +00:00 [Information] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed action SignService.Controllers.SignController.SignFile (SignService) in 18106.2415ms
2021-09-02 18:14:08.988 +00:00 [Information] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executed endpoint 'SignService.Controllers.SignController.SignFile (SignService)'
2021-09-02 18:14:09.264 +00:00 [Error] Microsoft.AspNetCore.Server.IIS.Core.IISHttpServer: Connection ID "14771806779385839720", Request ID "80000072-0000-cd00-b63f-84710c7967ab": An unhandled exception was thrown by the application.System.AggregateException: One or more errors occurred. (Could not append sign C:\local\Temp\b04q102l.p3s\cg2gsarj.exe)---> System.Exception: Could not append sign C:\local\Temp\b04q102l.p3s\cg2gsarj.exeat SignService.AzureSignToolSignService.<>c__DisplayClass6_0.<SubmitInternal>b__0(String file, ParallelLoopState state) in C:\Dev\RD\SignService\src\SignService\SigningTools\AzureSignToolSignService.cs:line 62at System.Threading.Tasks.Parallel.<>c__DisplayClass33_0`2.<ForEachWorker>b__1(Int32 i, ParallelLoopState state)at System.Threading.Tasks.Parallel.<>c__DisplayClass19_0`1.<ForWorker>b__1(RangeWorker& currentWorker, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)--- End of stack trace from previous location where exception was thrown ---at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw(Exception source)at System.Threading.Tasks.Parallel.<>c__DisplayClass19_0`1.<ForWorker>b__1(RangeWorker& currentWorker, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)at System.Threading.Tasks.TaskReplicator.Replica`1.ExecuteAction(Boolean& yieldedBeforeCompletion)at System.Threading.Tasks.TaskReplicator.Replica.Execute()--- End of inner exception stack trace ---at System.Threading.Tasks.TaskReplicator.Run[TState](ReplicatableUserAction`1 action, ParallelOptions options, Boolean stopOnFirstFailure)at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)--- End of stack trace from previous location where exception was thrown ---at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw(Exception source)at System.Threading.Tasks.Parallel.ThrowSingleCancellationExceptionOrOtherException(ICollection exceptions, CancellationToken cancelToken, Exception otherException)at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)at System.Threading.Tasks.Parallel.ForEachWorker[TSource,TLocal](IList`1 list, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Action`3 bodyWithStateAndIndex, Func`4 bodyWithStateAndLocal, Func`5 bodyWithEverything, Func`1 localInit, Action`1 localFinally)at System.Threading.Tasks.Parallel.ForEachWorker[TSource,TLocal](IEnumerable`1 source, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Action`3 bodyWithStateAndIndex, Func`4 bodyWithStateAndLocal, Func`5 bodyWithEverything, Func`1 localInit, Action`1 localFinally)at System.Threading.Tasks.Parallel.ForEach[TSource](IEnumerable`1 source, Action`2 body)at SignService.AzureSignToolSignService.SubmitInternal(HashMode hashMode, String name, String description, String descriptionUrl, IList`1 files) in C:\Dev\RD\SignService\src\SignService\SigningTools\AzureSignToolSignService.cs:line 54at SignService.AzureSignToolSignService.<>c__DisplayClass5_0.<Submit>b__0() in C:\Dev\RD\SignService\src\SignService\SigningTools\AzureSignToolSignService.cs:line 42at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)--- End of stack trace from previous location where exception was thrown ---at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)--- End of stack trace from previous location where exception was thrown ---at SignService.SigningTools.SigningToolAggregate.Submit(HashMode hashMode, String name, String description, String descriptionUrl, IList`1 files, String filter) in C:\Dev\RD\SignService\src\SignService\SigningTools\SigningToolAggregate.cs:line 191at SignService.Controllers.SignController.SignFile(IFormFile source, IFormFile filelist, HashMode hashMode, String name, String description, String descriptionUrl) in C:\Dev\RD\SignService\src\SignService\Controllers\SignController.cs:line 102at lambda_method(Closure , Object )at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Logged|12_1(ControllerActionInvoker invoker)at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|24_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|19_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1.ProcessRequestAsync()
2021-09-02 18:14:09.303 +00:00 [Information] Microsoft.AspNetCore.Hosting.Diagnostics: Request finished in 19949.977ms 500

Thoorium avatar Sep 02 '21 18:09 Thoorium

I dont know how much help this is but from the Err tool:

E:\GitHub\runtimelab2>e:\Err_6.4.5.exe 80190193
# No results found for hex 0x4c79af1 / decimal 80190193
# for hex 0x80190193 / decimal -2145844845
  BG_E_HTTP_ERROR_403                                            bitsmsg.h
  HTTP_E_STATUS_FORBIDDEN                                        winerror.h
# Forbidden (403).
# as an HRESULT: Severity: FAILURE (1), FACILITY_HTTP (0x19), Code 0x193
# for hex 0x193 / decimal 403
  ERROR_PROCESS_MODE_NOT_BACKGROUND                              winerror.h
# The process is not in background processing mode.
# 3 matches found for "80190193"

The service is running ok? If its on a free plan, it can run out of quotas, but I don't remember if this is the code for that.

yowl avatar Sep 02 '21 22:09 yowl

Thank you for your reply. The service is running on a B1 instance with more than 9GB of free space available. At some point I suspected that something prevented write on disk but my executable is copied without issues to the host. Could it have something to do with SignTool.exe not being able to modify the file in the temp folder?

Thoorium avatar Sep 02 '21 22:09 Thoorium