Potential Temporal workers activity mix up?

[algirdasci]

Hey,

We have been using Temporal Cloud for our workflows for couple months now. Recently, we had downtime caused by non-deterministic Temporal error:

[TMPRL1100] lookup failed for scheduledEventID to activityID: scheduleEventID: 24, activityID: 24

Even though we did not had any deployments / code change hour prior this downtime, so I'm 100% sure the issue was not new code deployment. What we did had though was higher than usual volume of workflows dispatched (~2.5k) during short period of time. We have running one dedicated pod of RoadRunner with 8 Temporal workers, so they were very busy during execution, but resource usage history graph does not show anything abnormal. What is abnormal - the non-deterministic error was caused by activity execution, which should not belong to that workflow:

Workflow updates database based on action ID, so in this case it should be 64517126. The ID is immutable, so it cannot be changed in code and is preserved throughout workflow:

{
  "eventId": "1",
  "eventTime": "2025-10-30T15:07:14.150546506Z",
  "eventType": "WorkflowExecutionStarted",
  "version": "100761",
  "taskId": "51296161",
  "workflowExecutionStartedEventAttributes": {
    "workflowType": {
      "name": "Docker.Compose.Start.V1"
    },
    "taskQueue": {
      "name": "default",
      "kind": "TASK_QUEUE_KIND_NORMAL"
    },
    "input": {
      "payloads": [
        {
          "action_id": 64517126
        }
      ]
    },
}
...
...
{
  "eventId": "23",
  "eventTime": "2025-10-30T15:07:24.699735411Z",
  "eventType": "ActivityTaskScheduled",
  "version": "100761",
  "taskId": "51296222",
  "activityTaskScheduledEventAttributes": {
    "activityId": "23",
    "activityType": {
      "name": "Actions.V1.UpdateState"
    },
    "taskQueue": {
      "name": "default",
      "kind": "TASK_QUEUE_KIND_NORMAL"
    },
    "header": {},
    "input": {
      "payloads": [
        64511416,
        "error"
      ]
    }
},
{
  "eventId": "24",
  "eventTime": "2025-10-30T15:07:24.699780241Z",
  "eventType": "ActivityTaskScheduled",
  "version": "100761",
  "taskId": "51296223",
  "activityTaskScheduledEventAttributes": {
    "activityId": "24",
    "activityType": {
      "name": "Actions.V1.SendEvent"
    },
    "taskQueue": {
      "name": "default",
      "kind": "TASK_QUEUE_KIND_NORMAL"
    },
    "header": {},
    "input": {
      "payloads": [
        64517126,
        "event-name"
      ]
    }
}

You can see, that event ID 23 appeared with completely different action ID of 64511416 which should not be in this workflow in the first play and belongs to different workflow type, which also failed with same pattern, by the way. Events 23 and 24 shares atomically close timing, which makes me believe, that there might be some kind of race condition / message ID collision during reporting activities to Temporal, especially on higher load than usual. I'm thinking enabling max_jobs / max_memory_limit options to reload workers periodically. But maybe you have other insight what could have gone wrong here and how to prevent it from happening in the future?

Debug info:
RoadRunner version 2025.1.3
Laravel with roadrunner-php/laravel-bridge 6.30, PHP 8.3

.rr.base.yaml:

version: '3'
rpc:
  listen: 'tcp://127.0.0.1:6001'

server:
  command: 'php vendor/bin/rr-worker start'

status:
  address: 0.0.0.0:2114

logs:
  encoding: json
  mode: production
  level: info
  channels:
    app:
      level: ${LOG_LEVEL:-debug}
      encoding: json
      mode: production
    http:
      level: warn
      encoding: json
      mode: production

.rr.temporal.yaml

version: "3"

include:
  - .rr.base.yaml
        
temporal:
  address: <redacted>
  namespace: <redacted>
  tls:
    key: <redacted>
    cert: <redacted>
  activities:
    num_workers: 8

First logs after error started to occur:

1761832913469	2025-10-30T14:01:53.469Z	{"ts":1761832913468853816,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"ActivityWorker","Error":"workflow execution already completed","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833009930	2025-10-30T14:03:29.930Z	{"ts":1761833009930538247,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"ActivityWorker","Error":"workflow execution already completed","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833036827	2025-10-30T14:03:56.827Z	{"ts":1761833036827017577,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"WorkflowWorker","Error":"UnhandledCommand","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833087642	2025-10-30T14:04:47.642Z	{"ts":1761833087641781239,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"WorkflowWorker","Error":"workflow execution not found for workflow ID \"default\" and run ID \"9f8f790c-835f-4a61-bc91-57b8fb1b903d\"","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833091700	2025-10-30T14:04:51.700Z	{"ts":1761833091699956023,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"ActivityWorker","Error":"workflow execution already completed","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833097636	2025-10-30T14:04:57.636Z	{"ts":1761833097636646386,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"ActivityWorker","Error":"workflow execution already completed","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833118649	2025-10-30T14:05:18.649Z	{"ts":1761833118649588150,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"WorkflowWorker","Error":"workflow execution not found for workflow ID \"default\" and run ID \"a9b11707-32b9-45de-a003-26ced94acebd\"","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833165910	2025-10-30T14:06:05.910Z	{"ts":1761833165910608065,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"ActivityWorker","Error":"workflow execution already completed","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833186206	2025-10-30T14:06:26.206Z	{"ts":1761833186206106304,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"WorkflowWorker","Error":"workflow execution not found for workflow ID \"default\" and run ID \"14dfa8af-86d1-4d9c-bb63-beb95a6ad9fb\"","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833203977	2025-10-30T14:06:43.977Z	{"ts":1761833203977112886,"logger":"temporal","msg":"Task processing failed with error","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkerType":"WorkflowWorker","Error":"workflow execution not found for workflow ID \"default\" and run ID \"83cbd6ae-6b38-4d07-b94a-287c47538ea5\"","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}
1761833213972	2025-10-30T14:06:53.972Z	{"ts":1761833213972106214,"logger":"temporal","msg":"Activity complete after timeout.","Namespace":"application.ns","TaskQueue":"default","WorkerID":"roadrunner:default:4cc60886-a423-4ab5-ab2b-534d412f26e9","WorkflowID":"Docker.Compose.Projects.V1:948709","RunID":"019a3570-ea7d-72a5-8cf4-2216b8090655","ActivityType":"Actions.V1.UpdateState","Attempt":1,"Result":"<nil>","Error":"activity_pool_execute_activity: NoFreeWorkers:\n\tstatic_pool_exec:\n\tstatic_pool_exec","kubernetes_pod_name":"application-temporal-578f5cc5f4-q6fs5","kubernetes_host":"kube-cluster--554ac442-sjsc","kubernetes_pod_ip":"10.24.223.124","kubernetes_container_name":"application-temporal"}

[rustatian]

Hey @algirdasci 👋🏻
I guess we had a similar problem in SDK-PHP before. What is your SDK-PHP version?

[rustatian]

We're currently working to prevent state corruption when the WF goes down.

[algirdasci]

Does this mean you found the root cause of that issue? Because I've spoken with PHP SDK people and we also have theory, that my workflow error handling causes worker crash, which may lead to state corruption. More specifically, I was yielding activity in finally block of my try..catch block and sometimes it might end up accessing variable which was already unassigned by SDK exception handler. Anyway, now I've removed finally block and will monitor if that helped.

[rustatian]

Yeah, I saw your messages. I'm also in all these chats 😃
Errors in your workflow for sure can be a reason for these problems, since the WF worker is very sensitive to restarts. We're trying to prevent any past messages that are supposed to land in the previous WF (dead) from being processed and reject them properly in a new WF worker.

[algirdasci]

I'm closing this discussion - after removing activity yields from finally block no more issues with corrupting workflow histories.

[rustatian]

Hah, that's interesting, thanks for noting that 👍🏻