I have the following code which uses a semaphore to allow a maximum concurrency;
_semaphore = new SemaphoreSlim(0, _settings.MaximumConcurrentRequests);
....
//Release based on maximum. Without doing this, the semaphore is the maximum when starting and will therefore not process anything further
_semaphore.Release(_settings.MaximumConcurrentRequests);
....
try
{
if (_semaphore.CurrentCount == 0)
_logger.LogDebug("Semaphore limit reached for Case {caseId}", caseId);
//If we have reached maximum concurrency, there will be a delay here until that Task has completed.
await _semaphore.WaitAsync(token);
_logger.LogInformation("Processing Case: {caseId}", caseId);
await _httpService.ProcessCase(caseId, token);
}
catch (Exception ex)
{
_logger.LogError("{ex}", ex);
}
finally
{
_logger.LogDebug("Semaphore released for Case {caseId}", caseId);
_semaphore.Release();
}
The current settings allow 10 cases to be processed at any 1 time and I have 45 available within my test environment. The first 10 are completed, none of the subsequent cases are processed and I end up having to cancel them. Excerpt from logs;
2021-12-10 09:57:34.432 +00:00 [DBG] Adding case: "4e262c8e-9e32-461e-8b56-d2f679041514" to Tasks array
2021-12-10 09:57:34.432 +00:00 [DBG] Adding case: "290c5a7c-5b2f-4e63-8a78-0156dd705161" to Tasks array
2021-12-10 09:57:34.432 +00:00 [INF] Processing Case (HTTP): "40a15e58-e7b3-4143-8a63-06a80966a86f"
2021-12-10 09:57:34.432 +00:00 [INF] Processing Case (HTTP): "7f96ed9b-5c8c-42b3-9f05-20bf12f7a004"
2021-12-10 09:57:34.432 +00:00 [INF] Processing Case (HTTP): "b8a59367-abb2-4063-90dc-817707155c77"
2021-12-10 09:57:34.432 +00:00 [INF] Processing Case (HTTP): "9f285d28-9be3-460f-a5bc-6c806a436205"
2021-12-10 09:57:34.666 +00:00 [INF] Processing Case: "e3e1d60c-cf86-405a-8c12-9bc7903eaecb"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "978b7f55-0901-4187-9a2f-22ed234fcd12"
2021-12-10 09:57:34.682 +00:00 [INF] Processing Case (HTTP): "e3e1d60c-cf86-405a-8c12-9bc7903eaecb"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "804646f8-6421-4029-99d1-948952487c41"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "abdbe15b-bd11-42c1-9b1c-64544078ed45"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "3cbef0c2-17dc-420c-b30b-a7719325baf7"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "8566aa4a-c7e3-4caf-9a34-ff20cd97c4a0"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "acc3d22f-a53e-4869-a17b-be9f2917e5c1"
2021-12-10 09:57:34.682 +00:00 [DBG] Semaphore limit reached for Case "32ad7155-f519-49c0-8cd7-a620dd586175"
.....
2021-12-10 09:57:35.477 +00:00 [INF] Response : "OK" received for Case:"7f96ed9b-5c8c-42b3-9f05-20bf12f7a004"
2021-12-10 09:57:35.477 +00:00 [INF] Response : "OK" received for Case:"b8a59367-abb2-4063-90dc-817707155c77"
2021-12-10 09:57:35.477 +00:00 [INF] Response : "OK" received for Case:"e3e1d60c-cf86-405a-8c12-9bc7903eaecb"
2021-12-10 09:57:35.477 +00:00 [INF] Response : "OK" received for Case:"40a15e58-e7b3-4143-8a63-06a80966a86f"
2021-12-10 09:57:35.493 +00:00 [DBG] Semaphore released for Case "40a15e58-e7b3-4143-8a63-06a80966a86f"
2021-12-10 09:57:35.493 +00:00 [DBG] Semaphore released for Case "e3e1d60c-cf86-405a-8c12-9bc7903eaecb"
2021-12-10 09:57:35.493 +00:00 [DBG] Semaphore released for Case "b8a59367-abb2-4063-90dc-817707155c77"
2021-12-10 09:57:35.493 +00:00 [DBG] Semaphore released for Case "7f96ed9b-5c8c-42b3-9f05-20bf12f7a004"
2021-12-10 09:57:35.493 +00:00 [INF] Response : "OK" received for Case:"9f285d28-9be3-460f-a5bc-6c806a436205"
2021-12-10 09:57:35.493 +00:00 [DBG] Semaphore released for Case "9f285d28-9be3-460f-a5bc-6c806a436205"
....
Then nothing until I cancel.
2021-12-10 10:12:26.537 +00:00 [ERR] System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.Threading.ManualResetEventSlim.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
The code itself is contained within a single API. Essentially, the API exposes 2 methods ProcessBatch and ProcessCase and ProcessBatch will call ProcessCase over another http channel (this is load balanced). Interestingly, if the call to ProcessBatch is done from my local machine with the call to ProcessCase on the dev server, it works fine.
EDIT updated code to add additional debug information;
var result = _semaphore.Release();
_logger.LogDebug("Semaphore released for Case {caseId}, semaphore result {result}", caseId, result);
2021-12-10 12:01:34.706 +00:00 [INF] Response : "OK" received for Case:"abdbe15b-bd11-42c1-9b1c-64544078ed45"
2021-12-10 12:01:34.706 +00:00 [INF] Response : "OK" received for Case:"804646f8-6421-4029-99d1-948952487c41"
2021-12-10 12:01:34.706 +00:00 [INF] Response : "OK" received for Case:"3cbef0c2-17dc-420c-b30b-a7719325baf7"
2021-12-10 12:01:34.722 +00:00 [DBG] Semaphore released for Case "abdbe15b-bd11-42c1-9b1c-64544078ed45", semaphore result 0
2021-12-10 12:01:34.722 +00:00 [DBG] Semaphore released for Case "804646f8-6421-4029-99d1-948952487c41", semaphore result 2
2021-12-10 12:01:34.722 +00:00 [DBG] Semaphore released for Case "3cbef0c2-17dc-420c-b30b-a7719325baf7", semaphore result 1
2021-12-10 12:01:34.722 +00:00 [INF] Response : "OK" received for Case:"978b7f55-0901-4187-9a2f-22ed234fcd12"
2021-12-10 12:01:34.722 +00:00 [DBG] Semaphore released for Case "978b7f55-0901-4187-9a2f-22ed234fcd12", semaphore result 3
2021-12-10 12:01:34.722 +00:00 [INF] Response : "OK" received for Case:"04e1e60a-2ae9-4455-b391-f0b95a38544b"
2021-12-10 12:01:34.722 +00:00 [DBG] Semaphore released for Case "04e1e60a-2ae9-4455-b391-f0b95a38544b", semaphore result 4
This is the log file for calling ProcessBatch locally with then calls ProcessCase remotely, but identical code;
2021-12-10 12:05:47.936 +00:00 [DBG] Semaphore released for Case "f043a848-9abf-4b25-903c-2116169005b6", semaphore result 0
2021-12-10 12:05:47.936 +00:00 [DBG] Semaphore released for Case "1dcc23f6-411f-4f38-89a3-0613d8e2058d", semaphore result 0
2021-12-10 12:05:47.936 +00:00 [DBG] Semaphore released for Case "aabcbd73-6434-4097-99f8-f51b17b819d9", semaphore result 0
2021-12-10 12:05:47.936 +00:00 [DBG] Semaphore released for Case "acc3d22f-a53e-4869-a17b-be9f2917e5c1", semaphore result 0
2021-12-10 12:05:47.935 +00:00 [INF] Response : "OK" received for Case:"ff784399-c213-402d-b031-921a0ffd1367"
2021-12-10 12:05:47.936 +00:00 [DBG] Semaphore released for Case "ff784399-c213-402d-b031-921a0ffd1367", semaphore result 0
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case: "f35d4e1a-70f1-4b7a-af0b-06f553736726"
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case: "32ad7155-f519-49c0-8cd7-a620dd586175"
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case: "8566aa4a-c7e3-4caf-9a34-ff20cd97c4a0"
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case (HTTP): "8566aa4a-c7e3-4caf-9a34-ff20cd97c4a0"
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case: "293239fd-6888-413d-b67a-44f5f1eaf487"
2021-12-10 12:05:47.936 +00:00 [INF] Processing Case: "416e5527-894f-42ac-a6f6-56ef83c322e2"
It looks to me that as soon as the semaphore is released, one of the other Tasks that continues so this is only a problem with remote to remote but I fail to see why that would matter here.