Activity Function started multiple times before completion
Nobody has claimed this yet.
Assessment
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Newbie friendliness
- 25/100
- Issue type
- Bug
- Clarity
- Needs clarification
- Activity status
- Stale
- Tech stack
- azure, csharp
- Domain
- backend, cloud, distributed-systems
Research direction
Start with the StartOfDayUpsertActivity execution sequence and correlate its invocation IDs with the storage conflict, lease renewal, timeout, CPU, and thread-pool warnings in the logs. Determine why the activity is interrupted and replayed, then document a reproducible cause and prevention guidance for the reported behavior.
Written by the indexing model from the issue text.
Description
Summary:
We're observing instances where the same Activity Function, is being invoked multiple times before completing.
Additional information:
This Activity Function is started by an Orchestrator that awaits its completion. Although the Activity Function took around 35 seconds to be completely executed (when it succeeded), the Orchestrator's overall duration was more than 35 minutes.
From the correlated dependency logs, each time the Activity Function is invoked, it makes some progress, but it doesn't fully finish. There are no exceptions or errors during the processing; the Function seems to just "die" all of a sudden, and it is started again at a later time. It finally completed the execution more than 33 minutes after it was first invoked.
Logs:
The series of logs from the execution environment that show the recurring invocation of the Activity Function without successful completion:
4/30/2024, 11:19:16.877 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=d9480089-03b2-43c3-bb43-1ae28422bf90)
4/30/2024, 11:20:20.344 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=9635f32b-d150-41f1-98a1-7ac11e254a79)
4/30/2024, 11:24:45.411 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=59e01faf-f031-427c-a5db-4c59f7ea32f2)
4/30/2024, 11:25:36.743 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=cbd95782-2130-4385-a6c9-655e46bbd0e4)
4/30/2024, 11:28:45.263 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=25923d2c-9df4-47a2-824d-5f33c5b57489)
4/30/2024, 11:30:49.465 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=90e1f92f-e204-44f7-967a-884196c05952)
4/30/2024, 11:37:34.184 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=858b82c5-7691-40e4-940b-4ee405e2201c)
4/30/2024, 11:40:32.827 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=0e8b82a6-fc7a-4b92-84e6-10c03711c4c9)
4/30/2024, 11:44:36.547 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=611be298-bdb1-48eb-888e-1192e040d7d9)
4/30/2024, 11:45:51.290 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=68763aed-1b55-40e6-848c-48070bb23520)
4/30/2024, 11:47:25.412 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=4cb06969-3175-464e-8c8a-0c653957c43d)
4/30/2024, 11:48:57.625 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=c070d3ff-b8df-4f1a-a420-7852b16b936e)
4/30/2024, 11:50:28.654 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=83f41053-62a0-46db-b961-f39d40d2e4f5)
4/30/2024, 11:52:12.297 AM
Executing 'StartOfDayUpsertActivity' (Reason='(null)', Id=49445402-c24e-4066-9922-fca6a2c5e9b5)
4/30/2024, 11:52:45.042 AM
Executed 'StartOfDayUpsertActivity' (Succeeded, Id=49445402-c24e-4066-9922-fca6a2c5e9b5, Duration=34883ms)
At the same time, we observed various types of warnings, such as performance issues, storage conflicts, timeouts, and resource utilization alerts, that might be related to the unexpected behaviour described above. Here are some examples of such warnings:
Error response [8959bebe-ae91-4a2a-addb-8fd3476e538e] 409 The specified container already exists. (02.6s) Server:Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 x-ms-request-id:5599b6e0-301e-0061-73f0-9aa36d000000 x-ms-client-request-id:8959bebe-ae91-4a2a-addb-8fd3476e538e x-ms-version:2022-11-02 x-ms-error-code:ContainerAlreadyExists Date:Tue, 30 Apr 2024 11:19:14 GMT Content-Length:230 Content-Type:application/xml
Error response [2badf8bd-5897-48be-9fb5-9f2c29b52033] 409 There is already a lease present. (02.0s) Server:Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 x-ms-request-id:4885e259-c01e-0038-5ff0-9a24ee000000 x-ms-client-request-id:2badf8bd-5897-48be-9fb5-9f2c29b52033 x-ms-version:2022-11-02 x-ms-error-code:LeaseAlreadyPresent Date:Tue, 30 Apr 2024 11:19:15 GMT Content-Length:221 Content-Type:application/xml
Part00 Performance issue detected: storage operation PageBlobClient.DownloadStreamingAsync (ReadFromDevice) took 1.5s on attempt 1, which is excessive; id=7213 position=51179008 length=3584 operationReadRange=[51179008, 51182592]
Part10 Performance issue detected: RenewLeaseAsync took 2.4s, which is excessive; -11.871818500000003s past expiry
[HostMonitor] Host CPU threshold exceeded (87 >= 80)
Possible thread pool starvation detected.
Part01.0173103172 Dropped query 4890768R16 during recovery because it has timed out
Client.cc4e2ab Request cc4e2abR3 for partition 01 timed out
What could be the cause of the Activity Function not being completed, and started over and over again? And how can this be prevented?
- Dominant language
- C#
- Stars
- 239
- Forks
- 37
- Avg merge
- 1d 10h
- Merged PRs (30d)
- 2
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
More from microsoft/durabletask-netherite
-
Needs: Triage :mag:
Difficulty 4/5 3-5 days Newbie friendliness 25/100
-
Needs: Triage :mag:
Difficulty 5/5 Over a week Newbie friendliness 25/100
-
P1
Difficulty 4/5 3-5 days Newbie friendliness 35/100
-
P2
Difficulty 5/5 Over a week Newbie friendliness 20/100
microsoft/durabletask-netherite#447 · 1 comment ·
-
P2
Difficulty 2/5 1-3 hours Newbie friendliness 45/100
All issues in microsoft/durabletask-netherite
Similar issues
-
type/automation type/tech-debt
Difficulty 2/5 1-3 hours Newbie friendliness 78/100
-
bug
Difficulty 2/5 1-3 hours Newbie friendliness 88/100
-
t/bug
Difficulty 2/5 1-3 hours Newbie friendliness 82/100
-
ci-failure-cause test-failure
Difficulty 2/5 1-3 hours Newbie friendliness 82/100
-
area:auth FE mvp P3
Difficulty 2/5 1-3 hours Newbie friendliness 88/100
klasolsson81/jobbliggaren#1788 ·