SWF Schedules activities to disconnected workers still within 60 second polling window

[Jud]

My activity workers correctly process tasks 60% of the time, then they start throwing this error.

"I have not been able to poll successfully, and am now bailing out, with error undefined method `activity_type' for nil:NilClass"

Possibly something to do with the forking?

My workers look like:

AWS.config(access_key_id: AWS_SWF_ACTIVITY_KEY, secret_access_key: AWS_SWF_ACTIVITY_SECRET)

swf = AWS::SimpleWorkflow.new
domain = swf.domains[SWF_DOMAIN]

worker = AWS::Flow::ActivityWorker.new(swf.client, domain, task_list, ActivitiesClass)
worker.start if __FILE__ == $0

I'm running this worker on ubuntu/EC2.

@mjsteger

[Jud]

As a test, I performed the following with the workers as outlined above:

20.times do
  $rewquest_workflow_client.start_execution(b)
end

With the forking workers, there are many activities that are scheduled and "started" but never complete. The activity is a simple passthrough activity, without any real computation.

When I change to :use_forking => false, I run into no such issues, and 100% of the tasks complete, though the "I have not been able to poll successfully...." error is still being logged.

[mjsteger]

Looks like this is causing the error, as task can be nill if the poll is empty, and then it will ask for #activity_type on a nil object, getting the error you see. The reason why it doesn't occur when you turn forking off is because there is probably enough work that the polls aren't returning empty. We'll fix this up and get out a patch as soon as possible. Thanks for the great bug report!

[Jud]

@mjsteger this error could be a red herring -- I do get this error with :use_forking => false as well. Though, it will be nice to clean up that error message.

To restate the problem: When using a forking worker, jobs are accepted by the poller, but randomly never executed, and timeout.

[Jud]

@mjsteger after more testing, with :use_forking => false I can replicate the behavior where the activity worker accepts a task, but fails to execute, resulting in a timeout.

1. Start the worker
2. Immediately start an execution
3. Activity will be scheduled and started, but never executed

The task log looks like:

Mon Jan 20 11:11:46 GMT-500 2014 - 7 - WorkflowExecutionTimedOut
Mon Jan 20 11:09:46 GMT-500 2014 - 6 - ActivityTaskStarted
Mon Jan 20 11:09:46 GMT-500 2014 - 5 - ActivityTaskScheduled
Mon Jan 20 11:09:46 GMT-500 2014 - 4 - DecisionTaskCompleted
Mon Jan 20 11:09:46 GMT-500 2014 - 3 - DecisionTaskStarted
Mon Jan 20 11:09:46 GMT-500 2014 - 2 - DecisionTaskScheduled
Mon Jan 20 11:09:46 GMT-500 2014 - 1 - WorkflowExecutionStarted

The task is just a puts "hello", no reason for it to timeout. It seems like the poller is getting tasks, but maybe the process it is spinning up to execute the task isn't ready?

[mjsteger]

We're still looking into this issue. Just to be sure we're looking in the right place, you have a simple activity which simply puts, and you have a workflow which simply calls that one activity, correct? Also, the timeouts are probabilistic, correct? If so, can you comment on what % you see as failures, on average?

[Jud]

@mjsteger I'm working on a small script that shows the bug. I'll post it here.

[Jud]

@mjsteger after more testing, I've narrowed down the issue and I've reproduced it multiple times.

It seems like the TCP long polling connection isn't being terminated on the SWF end when an activity worker exits. I can reproduce with these steps (within the 60 second long polling window):

1. Start an activity task.
2. Stop an activity task.
3. Start an execution.

SWF seems to hand off the execution to the shutdown activity worker, and mark the task as started EVEN THOUGH the worker never actually processes the task. Looking at the debug logs you will see that the worker never even gets the task token.

Is this known behavior? It seems like the worker should be required to ack the token before a task is marked as started?

[pmohan6]

@Jud, thanks a lot for the clear repro. The problem you are seeing happens when a client disconnects while a long poll request is open. In this case the service may not realize the disconnect and dispatch a task thinking that the poller is still there. This is usually not a problem in production where you have workers running and polling for tasks on a continuous basis. But you may run into this more frequently in testing if you bring up and take down pollers quickly. This is not necessarily a problem in the Flow Framework, but we are looking into resolving it. In the meantime you can try using a different task list for each test run, for instance use a uuid. This will ensure that tasks for each run go to the new poller.

[Jud]

@pmohan6 Thanks for the idea of using a different task list, though, won't that require coordination between the deciders and the activity workers?

I know this isn't really an issue w/ the framework, and thanks for looking into it for me.

[Jud]

@pmohan6 @mjsteger -- I don't think I agree that this isn't an issue in production. For instance, when we upgrade code and restart our workers, any new executions will time out until the socket is closed. We deploy multiple times a day. Any pointers on how to do seamless activity upgrades that doesn't require modifying every workflow that uses the activity?

[Jud]

@mjsteger @pmohan6 Would it be possible to work around this issue using timers? E.g. start a 5 second timer when the Decider starts an activity, and have the activity cancel the timer?

The activity tasks are given something like 200 seconds to complete, so waiting for them to time out isn't an option.