Skip to content

Conversation

Copy link
Contributor

Copilot AI commented Jan 14, 2026

When OAuth tokens expire, concurrent lock acquisition failures trigger simultaneous connection refresh attempts. Each waiting thread was blindly closing and recreating the connection after acquiring the semaphore, causing connection thrashing and preventing requests from processing.

Additionally, lock messages were being published before consumers were set up, causing continuous timeout warnings when queues are recreated after deletion.

Changes

Added connection generation tracking to RabbitMqDistributedLockService:

  • connectionGeneration counter tracks refresh cycles
  • Threads capture generation before lock acquisition
  • ForceConnectionRefreshAsync skips refresh if generation changed (another thread already refreshed)

Reordered lock acquisition operations to prevent message delivery timeouts:

  • Consumer is set up BEFORE checking message count and publishing
  • This ensures messages are delivered immediately to existing consumers on quorum queues
  • Prevents timeout loops when queues are deleted and recreated

OAuth refresh flow:

// Before: All threads refresh, closing each other's connections
Thread1: Acquires semaphore → Refreshes connection (gen: 01)
Thread2: Acquires semaphore → Closes Thread1's connection → Refreshes (gen: 12)
Thread3: Acquires semaphore → Closes Thread2's connection → Refreshes (gen: 23)
// Result: Connection thrashing, requests stuck in pending

// After: Only first thread refreshes
Thread1: Captures gen=0 → Acquires semaphore → gen==0 → Refreshes (gen: 01)
Thread2: Captures gen=0 → Acquires semaphore → gen==1 → Skips refresh
Thread3: Captures gen=0 → Acquires semaphore → gen==1 → Skips refresh
// Result: Single refresh, all threads retry with fresh connection

Message delivery flow:

// Before: Message published before consumer exists
1. Check message count (0)
2. Publish lock message
3. Set up consumer (AFTER message published)
4. Timeout waiting for message ❌

// After: Consumer exists when message is published
1. Set up consumer FIRST
2. Check message count (0)
3. Publish lock message (consumer already exists)
4. Consumer receives message immediately

The generation check prevents redundant refreshes while preserving thread safety via the existing semaphore. The reordered operations ensure reliable message delivery on quorum queues.

Original prompt

This section details on the original issue you should resolve

<issue_title>attempts to reauth, but the requests are still in "pending"</issue_title>
<issue_description>[2026-01-13 16:51:47.055] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Forced RabbitMQ connection refresh to obtain new OAuth token
[2026-01-13 16:51:47.176] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:13] - OAuth 2.0 token automatically refreshed. Valid for 0 days, 0 hours, 59 minutes, 59 seconds
[2026-01-13 16:51:47.279] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Established RabbitMQ connection to backboneut:5671 with OAuth 2.0 automatic token refresh and SSL/TLS
[2026-01-13 17:51:47.955] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - ACCESS_REFUSED error on lock acquisition for 'env:Endur DV 18' - OAuth token may have expired. Refreshing connection and retrying (attempt 1/2)
RabbitMQ.Client.Exceptions.OperationInterruptedException: The AMQP operation was interrupted: AMQP close-reason, initiated by Peer, code=403, text='ACCESS_REFUSED - configure access to exchange 'dorc.dorc-qa-01' in vhost '/' refused for user 'd2615046-095f-4f57-bed7-53bee3843ca1', backend rabbit_auth_backend_oauth2 returned an error: "Provided JWT token has expired at timestamp 1768326707 (validat...', classId=40, methodId=10
at RabbitMQ.Client.Impl.Channel.ExchangeDeclareAsync(String exchange, String type, Boolean durable, Boolean autoDelete, IDictionary2 arguments, Boolean passive, Boolean noWait, CancellationToken cancellationToken) at RabbitMQ.Client.Impl.AutorecoveringChannel.ExchangeDeclareAsync(String exchange, String type, Boolean durable, Boolean autoDelete, IDictionary2 arguments, Boolean passive, Boolean noWait, CancellationToken cancellationToken)
at Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService.TryAcquireLockAsync(String resourceKey, Int32 leaseTimeMs, CancellationToken cancellationToken)
[2026-01-13 17:51:47.955] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - ACCESS_REFUSED error on lock acquisition for 'env:Endur DV 10' - OAuth token may have expired. Refreshing connection and retrying (attempt 1/2)
RabbitMQ.Client.Exceptions.OperationInterruptedException: The AMQP operation was interrupted: AMQP close-reason, initiated by Peer, code=403, text='ACCESS_REFUSED - configure access to exchange 'dorc.dorc-qa-01' in vhost '/' refused for user 'd2615046-095f-4f57-bed7-53bee3843ca1', backend rabbit_auth_backend_oauth2 returned an error: "Provided JWT token has expired at timestamp 1768326707 (validat...', classId=40, methodId=10
at RabbitMQ.Client.Impl.Channel.ExchangeDeclareAsync(String exchange, String type, Boolean durable, Boolean autoDelete, IDictionary2 arguments, Boolean passive, Boolean noWait, CancellationToken cancellationToken) at RabbitMQ.Client.Impl.AutorecoveringChannel.ExchangeDeclareAsync(String exchange, String type, Boolean durable, Boolean autoDelete, IDictionary2 arguments, Boolean passive, Boolean noWait, CancellationToken cancellationToken)
at Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService.TryAcquireLockAsync(String resourceKey, Int32 leaseTimeMs, CancellationToken cancellationToken)</issue_description>

Comments on the Issue (you are @copilot in this section)


✨ Let Copilot coding agent set things up for you — coding agent works faster and does higher quality work when set up for your repo.

Add connection generation tracking to prevent concurrent refresh thrashing when OAuth tokens expire. Multiple threads now check if another thread already refreshed the connection, avoiding redundant refreshes that caused requests to remain in pending state.

Co-authored-by: benhegartysefe <[email protected]>
Copilot AI changed the title [WIP] Fix pending requests after reauth attempts Fix OAuth token refresh race condition causing request backlog Jan 14, 2026
Copilot AI requested a review from benhegartysefe January 14, 2026 15:22
@benhegartysefe
Copy link
Contributor

@copilot noticed odd behaviour here is what i see in monitor logs:

[2026-01-15 16:44:33.429] [INFOR Dorc.Monitor.ComponentProcessor:] [T:15] - Processing of the PowerShell component '135 - Start Spread & Endur' failed.
[2026-01-15 16:44:33.438] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:15] - Removal of CancellationTokenSource for the request '1789648' failed.
[2026-01-15 16:44:33.501] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-15 16:44:39.475] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:44:45.123] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:44:50.869] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:44:56.596] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:02.184] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:07.928] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:13.725] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:19.414] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:25.106] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:30.762] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:36.300] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:42.002] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:47.671] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:53.279] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:45:58.849] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:14] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.
[2026-01-15 16:46:04.498] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:15] - Timeout waiting for lock message on 'env:Endur DV 10'. Another consumer may have claimed it.

Reorder operations to create consumer before publishing lock message. This prevents timeouts when messages are published before consumers exist. The consumer must exist when the message is published to ensure immediate delivery on quorum queues.

Co-authored-by: benhegartysefe <[email protected]>
Copy link
Contributor Author

Copilot AI commented Jan 15, 2026

@copilot noticed odd behaviour here is what i see in monitor logs:

[2026-01-15 16:44:33.429] [INFOR Dorc.Monitor.ComponentProcessor:] [T:15] - Processing of the PowerShell component '135 - Start S...

Fixed in commit 09e071a. The timeout issue was caused by publishing lock messages before setting up the consumer. Reordered the operations to create the consumer first, then publish - this ensures messages are delivered immediately on quorum queues.

Copilot AI changed the title Fix OAuth token refresh race condition causing request backlog Fix OAuth token refresh race condition and message delivery timeout Jan 15, 2026
@benhegartysefe
Copy link
Contributor

@copilot what I got on restart yesterday:

image

MonitorNonProd_20260119_DORC_UT2_1st_node.log

MonitorNonProd_20260119_DORC_UT2_2nd_node.log

there are token timeouts and lock acquisition errors in the logs

@benhegartysefe
Copy link
Contributor

@copilot [2026-01-19 17:34:33.648] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Cannot create deployment result since duplicate component with id '542' is detected.
[2026-01-19 17:34:33.997] [INFOR Dorc.Monitor.ComponentProcessor:] [T:16] - Deploying component with the name '1172 - Standard Crystal Templates' and id '542' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:34:34.022] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Server named pipe with the name 'DOrcMonitor-1789683' has started.
[2026-01-19 17:34:34.022] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789683'.
[2026-01-19 17:34:34.065] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:34:34.074] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:34:34.074] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Starting Runner process.
[2026-01-19 17:34:34.074] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789683 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789683.txt
[2026-01-19 17:34:34.078] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Completed Starting child process
[2026-01-19 17:34:34.693] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789683'.
[2026-01-19 17:34:35.002] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789683'.
[2026-01-19 17:34:56.269] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Runner finished for request ID '1789683' with result code [4294967295]
[2026-01-19 17:34:56.269] [ERROR Dorc.Monitor.ScriptDispatcher:] [T:16] - The Win32 exception with HRESULT error code is detected immediately after WaitForExit invocation. Message:The operation completed successfully.; Source: ; Data: System.Collections.ListDictionaryInternal; HelpLink: ; InnerException: ; TargetSite: .
[2026-01-19 17:34:56.269] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:16] - Runner process has been created.
[2026-01-19 17:34:56.276] [INFOR Dorc.Monitor.ComponentProcessor:] [T:16] - Processing of the PowerShell component '1172 - Standard Crystal Templates' failed.
[2026-01-19 17:34:56.310] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:16] - Removal of CancellationTokenSource for the request '1789683' failed.
[2026-01-19 17:34:56.354] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:34:57.858] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:16] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789684
[2026-01-19 17:34:57.868] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Attempting to deploy the request with id '1789684'.
[2026-01-19 17:34:58.011] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Setting Request to Running state, Id: 1789684
[2026-01-19 17:34:58.101] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Found 1 non-skipped components for request 1789684:
[2026-01-19 17:34:58.105] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Cannot create deployment result since duplicate component with id '1080' is detected.
[2026-01-19 17:34:58.105] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - No enabled non-skipped components are found for the request with id '1789684'.
[2026-01-19 17:34:58.113] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:16] - Removal of CancellationTokenSource for the request '1789684' failed.
[2026-01-19 17:34:58.207] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:34:59.871] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:19] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789685
[2026-01-19 17:34:59.882] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:19] - Attempting to deploy the request with id '1789685'.
[2026-01-19 17:35:00.054] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:19] - Setting Request to Running state, Id: 1789685
[2026-01-19 17:35:00.139] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:19] - Found 1 non-skipped components for request 1789685:
[2026-01-19 17:35:00.144] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:19] - Cannot create deployment result since duplicate component with id '3464' is detected.
[2026-01-19 17:35:00.303] [INFOR Dorc.Monitor.ComponentProcessor:] [T:19] - Deploying component with the name '1183 - Endur Admin Api' and id '3464' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:35:00.326] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "Trading.Endur.Admin.Api.Install.msi" }, { "productNames" : "Endur Admin Api*" } ] }.
[2026-01-19 17:35:00.326] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Server named pipe with the name 'DOrcMonitor-1789685' has started.
[2026-01-19 17:35:00.326] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789685'.
[2026-01-19 17:35:00.373] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:35:00.391] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:35:00.391] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Starting Runner process.
[2026-01-19 17:35:00.391] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789685 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789685.txt
[2026-01-19 17:35:00.395] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Completed Starting child process
[2026-01-19 17:35:01.040] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789685'.
[2026-01-19 17:35:01.376] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789685'.
[2026-01-19 17:36:06.863] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:12.450] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:17.941] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:23.529] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:29.069] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:29.545] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Runner finished for request ID '1789685' with result code [0]
[2026-01-19 17:36:29.545] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:19] - Runner process has been created.
[2026-01-19 17:36:29.547] [INFOR Dorc.Monitor.ComponentProcessor:] [T:19] - Processing of the PowerShell component '1183 - Endur Admin Api' completed.
[2026-01-19 17:36:29.557] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:19] - Removal of CancellationTokenSource for the request '1789685' failed.
[2026-01-19 17:36:29.613] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:36:29.618] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Error acquiring lock for 'env:Endur DV 10'
RabbitMQ.Client.Exceptions.OperationInterruptedException: The AMQP operation was interrupted: AMQP close-reason, initiated by Peer, code=541, text='INTERNAL_ERROR - failed consuming from quorum queue 'lock.env:Endur DV 10' in vhost '/': {shutdown,
delete}', classId=60, methodId=20
at RabbitMQ.Client.Impl.Channel.BasicConsumeAsync(String queue, Boolean autoAck, String consumerTag, Boolean noLocal, Boolean exclusive, IDictionary2 arguments, IAsyncBasicConsumer consumer, CancellationToken cancellationToken) at RabbitMQ.Client.Impl.AutorecoveringChannel.BasicConsumeAsync(String queue, Boolean autoAck, String consumerTag, Boolean noLocal, Boolean exclusive, IDictionary2 arguments, IAsyncBasicConsumer consumer, CancellationToken cancellationToken)
at Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService.TryAcquireLockAsync(String resourceKey, Int32 leaseTimeMs, CancellationToken cancellationToken)
[2026-01-19 17:36:34.609] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:34.610] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Error acquiring lock for 'env:Endur DV 18'
RabbitMQ.Client.Exceptions.AlreadyClosedException: Already closed: The AMQP operation was interrupted: AMQP close-reason, initiated by Peer, code=541, text='INTERNAL_ERROR - failed consuming from quorum queue 'lock.env:Endur DV 10' in vhost '/': {shutdown,
delete}', classId=60, methodId=20
at RabbitMQ.Client.Impl.SessionBase.ThrowAlreadyClosedException()
at RabbitMQ.Client.Impl.SessionBase.TransmitAsync[T](T& cmd, CancellationToken cancellationToken)
at RabbitMQ.Client.Impl.Channel.BasicCancelAsync(String consumerTag, Boolean noWait, CancellationToken cancellationToken)
at RabbitMQ.Client.Impl.AutorecoveringChannel.BasicCancelAsync(String consumerTag, Boolean noWait, CancellationToken cancellationToken)
at Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService.TryAcquireLockAsync(String resourceKey, Int32 leaseTimeMs, CancellationToken cancellationToken)
[2026-01-19 17:36:35.217] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - OAuth 2.0 token automatically refreshed. Valid for 0 days, 0 hours, 59 minutes, 59 seconds
[2026-01-19 17:36:35.345] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Established RabbitMQ connection to backboneut:5671 with OAuth 2.0 automatic token refresh and SSL/TLS
[2026-01-19 17:36:40.369] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:45.595] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:51.090] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:36:56.614] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:02.091] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:07.747] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:13.280] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:18.810] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:24.376] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:30.274] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:36.097] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:41.698] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:47.379] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:52.851] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:37:58.420] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:04.139] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:06.652] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:12] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789687
[2026-01-19 17:38:06.656] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Attempting to deploy the request with id '1789687'.
[2026-01-19 17:38:06.739] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Setting Request to Running state, Id: 1789687
[2026-01-19 17:38:06.774] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Found 1 non-skipped components for request 1789687:
[2026-01-19 17:38:06.776] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Cannot create deployment result since duplicate component with id '3588' is detected.
[2026-01-19 17:38:06.927] [INFOR Dorc.Monitor.ComponentProcessor:] [T:12] - Deploying component with the name '1185 - Endur Reference Api' and id '3588' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:38:06.947] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "Trading.Endur.Reference.Api.Install.msi" }, { "productNames" : "Endur Reference Api*" } ] }.
[2026-01-19 17:38:06.948] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Server named pipe with the name 'DOrcMonitor-1789687' has started.
[2026-01-19 17:38:06.948] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789687'.
[2026-01-19 17:38:07.006] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:38:07.016] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:38:07.016] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Starting Runner process.
[2026-01-19 17:38:07.016] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789687 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789687.txt
[2026-01-19 17:38:07.115] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Completed Starting child process
[2026-01-19 17:38:09.152] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789687'.
[2026-01-19 17:38:09.474] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789687'.
[2026-01-19 17:38:09.743] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:15.367] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:20.966] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:25] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:26.700] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:32.188] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:37.822] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:43.409] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:48.982] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:38:54.699] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:00.583] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:06.328] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:11.867] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:17.626] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:23.212] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:28.784] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:31.770] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner finished for request ID '1789687' with result code [0]
[2026-01-19 17:39:31.770] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner process has been created.
[2026-01-19 17:39:31.774] [INFOR Dorc.Monitor.ComponentProcessor:] [T:12] - Processing of the PowerShell component '1185 - Endur Reference Api' completed.
[2026-01-19 17:39:31.783] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:12] - Removal of CancellationTokenSource for the request '1789687' failed.
[2026-01-19 17:39:31.873] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:39:34.354] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:40.030] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:45.649] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:51.193] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:39:56.859] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:02.461] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:08.158] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:13.742] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:19.647] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:25.439] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:30.996] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:36.517] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:42.073] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:47.613] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:53.184] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:40:53.806] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:12] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789689
[2026-01-19 17:40:53.809] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Attempting to deploy the request with id '1789689'.
[2026-01-19 17:40:53.877] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Setting Request to Running state, Id: 1789689
[2026-01-19 17:40:53.907] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Found 1 non-skipped components for request 1789689:
[2026-01-19 17:40:53.909] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:12] - Cannot create deployment result since duplicate component with id '3508' is detected.
[2026-01-19 17:40:54.169] [INFOR Dorc.Monitor.ComponentProcessor:] [T:12] - Deploying component with the name '11611 - Endur DLC Trade Uploader Service' and id '3508' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:40:54.197] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "Trading.Endur.Dlc.TradeUploader.Installer.msi" }, { "productNames" : "Endur DLC Trade Uploader Service*" } ] }.
[2026-01-19 17:40:54.197] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Server named pipe with the name 'DOrcMonitor-1789689' has started.
[2026-01-19 17:40:54.197] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:16] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789689'.
[2026-01-19 17:40:54.241] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:40:54.250] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:40:54.250] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Starting Runner process.
[2026-01-19 17:40:54.250] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789689 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789689.txt
[2026-01-19 17:40:54.255] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Completed Starting child process
[2026-01-19 17:40:54.888] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:16] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789689'.
[2026-01-19 17:40:55.209] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:16] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789689'.
[2026-01-19 17:40:58.756] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:04.458] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:10.104] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:15.738] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:21.387] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:27.006] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:32.622] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:38.064] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:43.583] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:49.148] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:41:54.631] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:00.179] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:05.790] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:09.795] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner finished for request ID '1789689' with result code [0]
[2026-01-19 17:42:09.795] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:12] - Runner process has been created.
[2026-01-19 17:42:09.804] [INFOR Dorc.Monitor.ComponentProcessor:] [T:12] - Processing of the PowerShell component '11611 - Endur DLC Trade Uploader Service' completed.
[2026-01-19 17:42:09.839] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:12] - Removal of CancellationTokenSource for the request '1789689' failed.
[2026-01-19 17:42:09.976] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:42:10.355] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789690
[2026-01-19 17:42:10.364] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Attempting to deploy the request with id '1789690'.
[2026-01-19 17:42:10.498] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Setting Request to Running state, Id: 1789690
[2026-01-19 17:42:10.607] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Found 1 non-skipped components for request 1789690:
[2026-01-19 17:42:10.612] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Cannot create deployment result since duplicate component with id '3509' is detected.
[2026-01-19 17:42:10.831] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Deploying component with the name '11612 - Endur DLC Trade Validator Service' and id '3509' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:42:10.850] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "Trading.Endur.Dlc.TradeValidator.Installer.msi" }, { "productNames" : "Endur DLC Trade Validator Service*" } ] }.
[2026-01-19 17:42:10.851] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Server named pipe with the name 'DOrcMonitor-1789690' has started.
[2026-01-19 17:42:10.851] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789690'.
[2026-01-19 17:42:10.905] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:42:10.917] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:42:10.917] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Starting Runner process.
[2026-01-19 17:42:10.917] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789690 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789690.txt
[2026-01-19 17:42:10.921] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Completed Starting child process
[2026-01-19 17:42:11.488] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:11.596] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789690'.
[2026-01-19 17:42:11.906] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789690'.
[2026-01-19 17:42:17.344] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:23.025] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:28.613] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:34.140] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:39.675] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:45.289] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:50.754] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:42:56.284] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:02.053] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:07.778] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:13.324] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:18.877] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:24.460] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:30.083] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:32.829] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner finished for request ID '1789690' with result code [0]
[2026-01-19 17:43:32.829] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner process has been created.
[2026-01-19 17:43:32.831] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Processing of the PowerShell component '11612 - Endur DLC Trade Validator Service' completed.
[2026-01-19 17:43:32.843] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Removal of CancellationTokenSource for the request '1789690' failed.
[2026-01-19 17:43:32.905] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:43:35.572] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:41.098] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:46.699] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:52.269] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:43:57.779] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:03.506] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:09.114] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:14.850] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:20.565] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:26.285] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:31.803] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:37.419] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:43.266] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:48.725] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:44:54.441] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:00.101] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:05.799] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:11.622] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:17.318] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:22.968] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:28.498] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:34.065] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:39.635] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:45.221] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:50.885] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:45:56.470] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:02.090] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:07.789] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:13.608] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:19.164] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:24.760] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:30.462] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:36.069] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:41.732] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:47.399] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:52.954] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:46:58.415] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:04.000] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:16] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:09.727] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:15.315] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:20.838] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:26.629] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:31.995] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:37.477] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:43.003] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:48.491] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:54.037] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:47:59.679] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:05.200] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:05.862] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789693
[2026-01-19 17:48:05.866] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Attempting to deploy the request with id '1789693'.
[2026-01-19 17:48:05.929] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Setting Request to Running state, Id: 1789693
[2026-01-19 17:48:05.960] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Found 1 non-skipped components for request 1789693:
[2026-01-19 17:48:05.962] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Cannot create deployment result since duplicate component with id '3512' is detected.
[2026-01-19 17:48:06.142] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Deploying component with the name '11616 - Endur DLC Payoff Uploader Service' and id '3512' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:48:06.148] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "Trading.Endur.Dlc.PayoffUploader.Installer.msi" }, { "productNames" : "Endur DLC Payoff Uploader Service*" } ] }.
[2026-01-19 17:48:06.148] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Server named pipe with the name 'DOrcMonitor-1789693' has started.
[2026-01-19 17:48:06.148] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:21] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789693'.
[2026-01-19 17:48:06.310] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:48:06.313] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:48:06.313] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Starting Runner process.
[2026-01-19 17:48:06.313] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789693 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789693.txt
[2026-01-19 17:48:06.317] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Completed Starting child process
[2026-01-19 17:48:06.928] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:21] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789693'.
[2026-01-19 17:48:07.220] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:21] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789693'.
[2026-01-19 17:48:10.811] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:16.250] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:21.734] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:27.387] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:32.990] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:38.514] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:44.024] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:49.734] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:48:55.229] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:00.864] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:21] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:06.481] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:12.106] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:17.623] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:20.799] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner finished for request ID '1789693' with result code [0]
[2026-01-19 17:49:20.799] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner process has been created.
[2026-01-19 17:49:20.802] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Processing of the PowerShell component '11616 - Endur DLC Payoff Uploader Service' completed.
[2026-01-19 17:49:20.811] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Removal of CancellationTokenSource for the request '1789693' failed.
[2026-01-19 17:49:20.863] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:49:22.062] [INFOR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Acquired distributed lock for environment 'Endur DV 10' to process request 1789694
[2026-01-19 17:49:22.065] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Attempting to deploy the request with id '1789694'.
[2026-01-19 17:49:22.141] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Setting Request to Running state, Id: 1789694
[2026-01-19 17:49:22.174] [INFOR Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Found 1 non-skipped components for request 1789694:
[2026-01-19 17:49:22.186] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:22] - Cannot create deployment result since duplicate component with id '488' is detected.
[2026-01-19 17:49:22.334] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Deploying component with the name '11617 - ZEMA Endur Prices Service' and id '488' of type 'PowerShell' (Enum Value: 0).
[2026-01-19 17:49:22.340] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Found a JSON Path with { "ScriptPath": "00 Generic\DeployMSI.ps1", "GenericArguments": [ { "msiName": "ZemaToEndurServiceInstaller.msi" }, { "productNames" : "Endur Prices & Curves Interface*" } ] }.
[2026-01-19 17:49:22.340] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Server named pipe with the name 'DOrcMonitor-1789694' has started.
[2026-01-19 17:49:22.341] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Waiting for pipe client to connect. Pipe name: 'DOrcMonitor-1789694'.
[2026-01-19 17:49:22.395] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Logon as svc-live-deploy-nonp succeeded
[2026-01-19 17:49:22.407] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner with the file full name 'C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe' is chosen.
[2026-01-19 17:49:22.407] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Starting Runner process.
[2026-01-19 17:49:22.407] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - About to start process C:\Program Files\DOrc\Deploy\Services\ActionServiceNonProd\DeployRunner\Dorc.NetFramework.Runner.exe with args Dorc.NetFramework.Runner.exe -pDOrcMonitor-1789694 -lc:\Log\DOrc\Deploy\Services\Requests\DOrcMonitor-1789694.txt
[2026-01-19 17:49:22.411] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Completed Starting child process
[2026-01-19 17:49:23.079] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has connected. Pipe name: 'DOrcMonitor-1789694'.
[2026-01-19 17:49:23.301] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:23.414] [INFOR Dorc.Monitor.Pipes.ScriptGroupPipeServer:] [T:5] - Pipe client has received serialized ScriptGroup. Pipe name: 'DOrcMonitor-1789694'.
[2026-01-19 17:49:28.861] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:34.479] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:40.158] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:45.766] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:51.287] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:49:57.221] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:02.884] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:08.453] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:14.204] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:19.785] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:25.575] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:3] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:31.082] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:36.622] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:42.128] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:43.328] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner finished for request ID '1789694' with result code [0]
[2026-01-19 17:50:43.328] [INFOR Dorc.Monitor.ScriptDispatcher:] [T:22] - Runner process has been created.
[2026-01-19 17:50:43.330] [INFOR Dorc.Monitor.ComponentProcessor:] [T:22] - Processing of the PowerShell component '11617 - ZEMA Endur Prices Service' completed.
[2026-01-19 17:50:43.342] [ERROR Dorc.Monitor.DeploymentRequestStateProcessor:] [T:22] - Removal of CancellationTokenSource for the request '1789694' failed.
[2026-01-19 17:50:43.399] [INFOR Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Deleted lock queue 'lock.env:Endur DV 10' for resource 'env:Endur DV 10' after deployment completed
[2026-01-19 17:50:47.654] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:53.320] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:50:58.908] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:04.415] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:10.066] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:12] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:15.660] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:21.402] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:22] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:26.920] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:19] - Timeout waiting for lock message on 'env:Endur DV 18'. Another consumer may have claimed it.
[2026-01-19 17:51:32.413] [WARNI Dorc.Monitor.HighAvailability.RabbitMqDistributedLockService:] [T:5]

Copy link
Contributor Author

Copilot AI commented Jan 20, 2026

@copilot [2026-01-19 17:34:33.648] [WARNI Dorc.Monitor.RequestProcessors.PendingRequestProcessor:] [T:16] - Cannot create deployment result since duplicate component with id '542' is detected.
[2026-0...

The log excerpt shows normal deployment processing with a duplicate component warning, which is expected behavior when a component appears multiple times in a build definition. This warning doesn't prevent deployment completion.

The "Pending" status in the screenshot appears to be a different issue unrelated to the OAuth/lock fixes. Could you share the specific token timeout or lock acquisition error messages you're seeing? I need to see errors like "ACCESS_REFUSED", "OAuth token may have expired", or "Timeout waiting for lock message" to diagnose issues with my changes.

…oken refresh

- Fix inverted logic in RemoveCancellationTokenSource that was incorrectly
  logging successful removals as errors (changed to debug level for not-found case)
- Add proactive OAuth token refresh 5 minutes before expiry to prevent
  ACCESS_REFUSED errors during lock acquisition
- Track token expiry time and check before each lock acquisition attempt

Co-Authored-By: Claude Opus 4.5 <[email protected]>
@github-actions
Copy link

github-actions bot commented Jan 20, 2026

Test Results

0 tests  ±0   0 ✅ ±0   0s ⏱️ ±0s
1 suites ±0   0 💤 ±0 
1 files   ±0   0 ❌ ±0 

Results for commit b324580. ± Comparison against base commit 8fdbaf4.

♻️ This comment has been updated with latest results.

benhegartysefe and others added 2 commits January 20, 2026 12:10
Update test mocks to include the new IMonitorConfiguration dependency
added to DeploymentEngine constructor.

Co-Authored-By: Claude Opus 4.5 <[email protected]>
@kirill-suspitsin-ext-sefe kirill-suspitsin-ext-sefe marked this pull request as ready for review January 23, 2026 11:12
@kirill-suspitsin-ext-sefe kirill-suspitsin-ext-sefe merged commit d5d8469 into main Jan 23, 2026
4 checks passed
@kirill-suspitsin-ext-sefe kirill-suspitsin-ext-sefe deleted the copilot/fix-oauth-token-refresh-issue branch January 23, 2026 11:15
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

attempts to reauth, but the requests are still in "pending"

3 participants