Adding timeout functionality to action nodes for ineffectual work functions #62

joshc-slac · 2024-10-19T01:29:13Z

Description

Want to allow work function of ActionNode's ActionWorker to timeout.

Specifically if the action performed in the work function is ineffectual. I.e. the work done in the work function never satisfies the completion condition. This does not guard against the case in which the work function itself hangs.

This motivated:

Moving the wrapped_action_work to the ActionWorker, keeps file sizes and contents reasonable. This did lead to what may be considered a pythonic sin of a pass-through definition in ActionNode; however for generally cleanliness of code base I would strongly argue this is best.
Creating a helper Timer class. One can imagine this will be used elsewhere. This can also extend the time.perf_counter method to be a code timer across the codebase

Motivation and Context

We want our work functions to be able to timeout. Notably this does not address the very real issue #56, but it is critical our trees be intelligent enough to stop work on a meaningful time horizon and report failure should they be unable to execute their task . This does not address #66

How Has This Been Tested?

Only in unit tests

Where Has This Been Documented?

We should do that more. I will do a little here.

Our work wrapper's wrapper now takes an additional, optional work_function_timeout_period_sec

BEAMS/beams/behavior_tree/ActionWorker.py

Line 32 in d49a5ee

    
           def wrapped_action_work(loop_period_sec: float = 0.1, work_function_timeout_period_sec: float = 2):

We initialize the Timer object (within the spawned process), using this new parameter

BEAMS/beams/behavior_tree/ActionWorker.py

Lines 51 to 54 in d49a5ee

    
           work_loop_timeout_timer = Timer(name=name, 
        
                                           timer_period_seconds=work_function_timeout_period_sec, 
        
                                           auto_start=False, 
        
                                           is_periodic=True)

We use the timer as another mechanism to exit the work loop:

BEAMS/beams/behavior_tree/ActionWorker.py

Line 64 in d49a5ee

while not completion_condition() and not work_loop_timeout_timer.is_elapsed():

The final completion condition check is now more than perfunctory

BEAMS/beams/behavior_tree/ActionWorker.py

Lines 78 to 84 in d49a5ee

    
           # check if we exited loop because we timed out or we succeeded at task 
        
           if completion_condition(): 
        
               logger.debug(f"Worker for node ({name}) completed.") 
        
               volatile_status.set_value(py_trees.common.Status.SUCCESS) 
        
           else: 
        
               logger.debug(f"Worker for node ({name}) failed.") 
        
               volatile_status.set_value(py_trees.common.Status.FAILURE)

Pre-merge checklist

Code works interactively
Code follows the style guide
Code contains descriptive docstrings, including context and API
New/changed functions and methods are covered in the test suite where possible
Test suite passes locally
Test suite passes on GitHub Actions
Ran docs/pre-release-notes.sh and created a pre-release documentation page
Pre-release docs include context, functional descriptions, and contributors as appropriate

joshc-slac · 2024-10-19T01:43:34Z

Closes #45

tangkong

I have a lot of questions, but maybe I'm misunderstanding things.

tangkong · 2024-10-30T20:02:55Z

beams/sequencer/helpers/Timer.py

+        self.is_periodic = is_periodic
+        self.auto_start = auto_start
+        if (self.auto_start):
+            self.timer_start_time = time.time()


Here and throughout we should use time.monotonic, since we don't actually care about the wall clock.

tangkong · 2024-10-30T20:07:21Z

beams/behavior_tree/ActionWorker.py

+                volatile_status.set_value(py_trees.common.Status.RUNNING)
+                # Start timer
+                work_loop_timeout_timer.start_timer()
+                while not completion_condition() and not work_loop_timeout_timer.is_elapsed():


Since we only check the timer at the top of the while loop, if a work function never completes / hangs forever, this won't actually timeout will it?

yes, at present this doesn't have a mechanism to send a kill signal to a hung function. Within Worker we can tie these functionalities together... it is a good, deeper idea. The intention here was if futile work was being done, i.e. the function is returning but having no effect on the success condition, to time out that work

tangkong · 2024-10-30T20:13:12Z

beams/behavior_tree/ActionWorker.py

+            work_loop_timeout_timer = Timer(name=name,
+                                            timer_period_seconds=work_function_timeout_period_sec,
+                                            auto_start=False,
+                                            is_periodic=True)


What's the intent behind the periodic timer here? It looks like we just reset the start time if the elapsed time is greater than the timer period. But the way the timer is called, the loop will never repeat within one work wrapper call (while loop starts -> work loops a couple times -> timer elapses -> while loop broken (even though timer started again))

So we want the (do_work) while loop, the one that launches this "thread" as a persistent process across the life cycle of the program to persist.

I was adding a timer to the actual "behavior tree load" this can be seen as, "I got initialized, I did my task for [loop_timer] amount of time, I never found my success condition to be true, let me signal fail and wait for the BT to try me again should it do so"

I think there's no disagreement that there needs to be a timer
The question here is: why is the timer periodic?
After all, on line 63 we manually restart the timer anyway. What does periodicity do here?

tangkong · 2024-10-30T20:18:52Z

beams/tests/test_leaf_node.py

+        Status.FAILURE,
+    ):
+        time.sleep(0.01)
+        action.tick_once()


Is this testing the right thing? The timeout is supposed to trigger within a tick right? Should the sleep be within the work function?

I think this test is correct, the sleep here is more like the tree's tick rate

ZLLentz · 2024-10-31T18:33:32Z

beams/sequencer/helpers/Timer.py

+            if (self.is_periodic):
+                self.timer_start_time = time.time()
+            return True


Can you explain what this periodic clause would be used for?
It's unintuitive that a timer would restart itself when checked.

This is a great point. It was more out of habit from previously implemented timers that I found the pattern of "one shot" vs "periodic" timer distinction helpful. Here I am not sure if there is much (or may even be negative) value add. Let me reflect for a moment

Okay on further reflection. You are 100% right that the timer within ActionWorker does not need to be periodic. I would however like to keep the notion of periodic timer in its current implementation for this use case:

A periodic timer when checked if elapsed (and it is) will emit a rising edge signal that is lowered thereafter which is convenient for breaking out of loops at fixed frequency, if not set as periodic the elapsed signal will stay high

https://en.wikipedia.org/wiki/You_aren%27t_gonna_need_it I might advocate for adding this when we need it, if we later discover we need it.

Is the distinction between a stays-high signal and a periodic-break signal even relevant here in python land? We should design our "signals" in the way that works for our use case

ZLLentz · 2024-10-31T18:33:44Z

beams/sequencer/helpers/Timer.py

pep8 says module names should be lowercase

I guess you don't have to change it because we need to do a mass update later to bring the package into compliance

ZLLentz · 2024-10-31T18:35:55Z

beams/sequencer/helpers/Timer.py

+import time
+
+
+class Timer():


Mixed feelings about this class name because it collides with threading.Timer from the standard library

ZLLentz

I'm going to approve because the core seems fully correct to me and I'm quibbling on some secondary things

ZLLentz · 2024-11-04T21:43:50Z

beams/tests/test_timer.py

+class TestTimer():
+    def test_elapsed(self):
+        t = Timer(name="test_elapsed",
+                  timer_period_seconds=0.1,
+                  is_periodic=False)
+        t.start_timer()
+        assert t.is_elapsed() is False
+        time.sleep(0.5)
+        assert t.is_elapsed() is True
+
+    def test_timer_error(self):
+        t = Timer(name="test_error_not_started",
+                  timer_period_seconds=0.1,
+                  is_periodic=False)
+        with pytest.raises(RuntimeError):
+            t.get_elapsed()
+        with pytest.raises(RuntimeError):
+            t.is_elapsed()
+
+    def test_periodic(self):
+        t = Timer(name="test_error_not_started",
+                  timer_period_seconds=0.1,
+                  auto_start=True,
+                  is_periodic=True)
+        time.sleep(0.2)
+        assert t.is_elapsed() is True
+        assert t.is_elapsed() is False
+        time.sleep(0.1)
+        assert t.is_elapsed() is True


2 layer Nitpick:

This class structure appears unnecessary to me

The assert statements are not pythonic. is True can be entirely omitted for truthiness checks and is False should use not instead.

Suggested change

class TestTimer():

def test_elapsed(self):

t = Timer(name="test_elapsed",

timer_period_seconds=0.1,

is_periodic=False)

t.start_timer()

assert t.is_elapsed() is False

time.sleep(0.5)

assert t.is_elapsed() is True

def test_timer_error(self):

t = Timer(name="test_error_not_started",

timer_period_seconds=0.1,

is_periodic=False)

with pytest.raises(RuntimeError):

t.get_elapsed()

with pytest.raises(RuntimeError):

t.is_elapsed()

def test_periodic(self):

t = Timer(name="test_error_not_started",

timer_period_seconds=0.1,

auto_start=True,

is_periodic=True)

time.sleep(0.2)

assert t.is_elapsed() is True

assert t.is_elapsed() is False

time.sleep(0.1)

assert t.is_elapsed() is True

def test_elapsed(self):

t = Timer(name="test_elapsed",

timer_period_seconds=0.1,

is_periodic=False)

t.start_timer()

assert not t.is_elapsed()

time.sleep(0.5)

assert t.is_elapsed()

def test_timer_error(self):

t = Timer(name="test_error_not_started",

timer_period_seconds=0.1,

is_periodic=False)

with pytest.raises(RuntimeError):

t.get_elapsed()

with pytest.raises(RuntimeError):

t.is_elapsed()

def test_periodic(self):

t = Timer(name="test_error_not_started",

timer_period_seconds=0.1,

auto_start=True,

is_periodic=True)

time.sleep(0.2)

assert t.is_elapsed()

assert not t.is_elapsed()

time.sleep(0.1)

assert t.is_elapsed()

ZLLentz

I left my nit and approving again

ZLLentz

Re-approval post nit

The base branch was changed.

joshc-slac · 2024-11-07T03:59:34Z

~~Hmmm @tangkong, casual ghub thought that our approval dismissing settings may be a tad over eager (or maybe it is I that is a tad overeager)~~

I just went down a small rabbit hole, our settings are probably sufficient and err in the correct direciton

… ActioNodeWorker, added functional timeout ability, tested

ZLLentz · 2024-11-07T18:17:58Z

I think the diff visualization is broken, it includes most of the elements from the refactor PR.

joshc-slac changed the base branch from master to joshc-slac/new-multi-shot October 19, 2024 01:29

joshc-slac force-pushed the joshc-slac/new-multi-shot branch 2 times, most recently from 573ab0b to dcefc01 Compare October 19, 2024 02:56

joshc-slac force-pushed the joshc-slac/timeout-action-node branch from d49a5ee to 8df553d Compare October 19, 2024 03:12

Base automatically changed from joshc-slac/new-multi-shot to master October 23, 2024 00:44

joshc-slac force-pushed the joshc-slac/timeout-action-node branch from 8df553d to a2c1edb Compare October 28, 2024 19:19

joshc-slac requested review from tangkong and ZLLentz October 28, 2024 19:19

tangkong reviewed Oct 30, 2024

View reviewed changes

ZLLentz reviewed Oct 31, 2024

View reviewed changes

ZLLentz previously approved these changes Oct 31, 2024

View reviewed changes

joshc-slac changed the title ~~Adding timeout functionality to action nodes~~ Adding timeout functionality to action nodes for ineffectual work functions Nov 4, 2024

joshc-slac dismissed ZLLentz’s stale review via 331cd0f November 4, 2024 20:08

joshc-slac force-pushed the joshc-slac/timeout-action-node branch from a2c1edb to 331cd0f Compare November 4, 2024 20:08

joshc-slac requested review from tangkong and ZLLentz November 4, 2024 20:09

ZLLentz reviewed Nov 4, 2024

View reviewed changes

ZLLentz previously approved these changes Nov 4, 2024

View reviewed changes

joshc-slac dismissed ZLLentz’s stale review via f069edb November 7, 2024 00:10

joshc-slac force-pushed the joshc-slac/timeout-action-node branch from 331cd0f to f069edb Compare November 7, 2024 00:10

joshc-slac changed the base branch from master to joshc-slac/better-conditions November 7, 2024 00:10

ZLLentz previously approved these changes Nov 7, 2024

View reviewed changes

Base automatically changed from joshc-slac/better-conditions to master November 7, 2024 03:57

joshc-slac added 2 commits November 6, 2024 20:03

feat(timer): adding timer utility

a822206

feat(ActionWorker, ActionNode, Timeout): moved wrapped_action_work to…

4ef010a

… ActioNodeWorker, added functional timeout ability, tested

joshc-slac added 2 commits November 6, 2024 20:03

chore: good nits

4131974

test timer nits

277f99c

ZLLentz approved these changes Nov 7, 2024

View reviewed changes

joshc-slac force-pushed the joshc-slac/timeout-action-node branch from 3a9badf to 277f99c Compare November 8, 2024 00:06

joshc-slac merged commit dd2395f into master Nov 8, 2024
14 checks passed

joshc-slac deleted the joshc-slac/timeout-action-node branch November 8, 2024 00:09

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Adding timeout functionality to action nodes for ineffectual work functions #62

Adding timeout functionality to action nodes for ineffectual work functions #62

joshc-slac commented Oct 19, 2024 •

edited

Loading

joshc-slac commented Oct 19, 2024

tangkong left a comment

tangkong Oct 30, 2024

tangkong Oct 30, 2024

joshc-slac Oct 30, 2024

tangkong Oct 30, 2024

joshc-slac Oct 30, 2024

ZLLentz Oct 31, 2024

tangkong Oct 30, 2024

ZLLentz Oct 31, 2024

ZLLentz Oct 31, 2024

joshc-slac Nov 4, 2024

joshc-slac Nov 4, 2024

tangkong Nov 4, 2024

ZLLentz Oct 31, 2024

ZLLentz Oct 31, 2024

ZLLentz Oct 31, 2024

ZLLentz left a comment

ZLLentz Nov 4, 2024

ZLLentz left a comment

ZLLentz left a comment

joshc-slac commented Nov 7, 2024 •

edited

Loading

ZLLentz commented Nov 7, 2024

	work_loop_timeout_timer = Timer(name=name,
	timer_period_seconds=work_function_timeout_period_sec,
	auto_start=False,
	is_periodic=True)

	# check if we exited loop because we timed out or we succeeded at task
	if completion_condition():
	logger.debug(f"Worker for node ({name}) completed.")
	volatile_status.set_value(py_trees.common.Status.SUCCESS)
	else:
	logger.debug(f"Worker for node ({name}) failed.")
	volatile_status.set_value(py_trees.common.Status.FAILURE)

Adding timeout functionality to action nodes for ineffectual work functions #62

Adding timeout functionality to action nodes for ineffectual work functions #62

Conversation

joshc-slac commented Oct 19, 2024 • edited Loading

Description

Motivation and Context

How Has This Been Tested?

Where Has This Been Documented?

Pre-merge checklist

joshc-slac commented Oct 19, 2024

tangkong left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ZLLentz left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ZLLentz left a comment

Choose a reason for hiding this comment

ZLLentz left a comment

Choose a reason for hiding this comment

joshc-slac commented Nov 7, 2024 • edited Loading

ZLLentz commented Nov 7, 2024

joshc-slac commented Oct 19, 2024 •

edited

Loading

joshc-slac commented Nov 7, 2024 •

edited

Loading