scripting: run functions asynchronously through the message API

[meyerj]

This is a better fix for #150 compared to the first proposal psoetens#7, which was too intrusive. It is based on @psoetens's master-update-hook-vs-callback-queue branch from #91.

Whenever a scripting function (or any other instance of ExecutableInterface) is called, the previous implementation added it to the runner's engine's function queue. With #91 this function queue is only processed if the component is triggered explicitly by either a timeout (if the component is periodic), an I/O event (in case it is running with a FileDescriptorActivity) or an explicit trigger() or update() call on the task. See the original PR for details.

With patch 32bdc3c the RTT::scripting::CallFunction implements the DisposableInterface and enqueues itself in the message queue of the executing engine instead of in the function queue. The message queue is processed asynchronously and does not wait for an explicit timeout or trigger event.

[snrkiwi]

Having the command now run asynchronously and "immediately" is a pretty significant change in semantics. I'm pretty sure that our systems would react poorly to such a change, and I imagine that this might likely affect other's systems also.

[meyerj]

More thoughts? I do not see a better alternative to fix issue #150 at the moment.

What would be possible is to execute functions asynchronously (without the need for an explicit trigger call) if the activity is non-periodic and synchronously for periodic activities. But it should be noted that the two cases cannot always be distinguished clearly, e.g. for the SlaveActivity or the FileDescriptorActivity.

[meyerj]

The new patches added last week are based on the work in meyerj#6 and #206. They do not change the essence of this PR, namely that calling scripting functions gets closer to the behavior of calling OwnThread operations and execute in the trigger step of the execution engine instead of waiting for a full update step.

The problematic cases are when other functions are called from the body or functions contain yield statements:

From meyerj#6:

Additional patch for #156 that enqueues the call in the function queue if the first execution as a message/operation returns without finishing the function (yield). [...]

From the commit message 611f3d1:

A yield statement within a function does not have a well-defined meaning if the function was called from the same thread that is supposed to execute it, especially if it is nested within another function. The ExecutionEngine::waitAndProcessFunctions() method, that was called in this case, processed all functions running in the same engine again, even if not related to the ongoing call, but did not process operations or invoke updateHook() before it returns. This is totally unexpected behavior because

• it's different from what a yield statement would do in programs, functions being sent or if the function
  is called from a different thread, in which case a yield pauses execution until the next update step and the execution engine always processes operations, port callbacks and updateHook() before it returns
• other waiting yields are unblocked and state machines are stepped again within the same update cycle
  because of the intermingled calls to ExecutionEngine::processFunctions().

With this patch a yield statement becomes almost a no-op in this case and only processes the message queue before it returns, which handles pending operation calls. Other than before the patch in 32bdc3c, that made all function calls execute immediately without the need to wait for the next update cycle, it is not required anymore to process all functions again while waiting for the completion of the current one. ExecutionEngine::processFunctions() is called exactly once per update step.

a5a6c95 and b2206bd are optimizations and only make the check for calling the same or another engine more explicit.

Example

## function_test.cpp
RTT::Attribute<int> i;

void printI() {
  log() << "  i = " << i << endlog();
}

void print(const std::string &text) {
  log() << text << endlog();
}

void updateHook() {
  log() << "updateHook()" << endlog();
}

## function_test.ops:
program backgroundTask {
  while(true) {
    print("backgroundTask triggered");
    yield;
  }
}

export void func1(void) {
  print("func1()");
}

export void func2(void) {
  print("func2()");
  i = i + 1;
  printI(i);
  yield;
  i = i + 1;
  printI(i);
}

export void func3(void) {
  print("func3()");
  func2();
}

backgroundTask.start();
start();
func1();
func2();
func3();

## deploy.ops
loadComponent("test", "FunctionTest");
test.setPeriod(1.0);
# or test.setPeriod(0.0);
test.scripting.runScript("function_test.ops");

Periodic activity

master/toolchain-2.8/toolchain-2.9 without this patch:

0.107 [ Info   ][loadComponent] Running Script function_test.ops ...
0.114 [ Info   ][ScriptingService] Loading Program 'backgroundTask'
0.117 [ Info   ][ScriptingService] Exported Function 'func1' added to task 'test'
0.123 [ Info   ][ScriptingService] Exported Function 'func2' added to task 'test'
0.125 [ Info   ][ScriptingService] Exported Function 'func3' added to task 'test'

1.111 [ Info   ][ScriptingService] backgroundTask triggered
1.111 [ Info   ][ScriptingService] func1()                  # <-- func1() executes synchronously
1.111 [ Info   ][ScriptingService] updateHook()

2.111 [ Info   ][ScriptingService] backgroundTask triggered
2.111 [ Info   ][ScriptingService] func2()                  # <-- func2() executes synchronously
2.111 [ Info   ][ScriptingService]   i = 1                  # <-- func2() yields
2.111 [ Info   ][ScriptingService] updateHook()

3.111 [ Info   ][ScriptingService] backgroundTask triggered
3.111 [ Info   ][ScriptingService]   i = 2                  # <-- func2() continues in the next cycle and returns
3.111 [ Info   ][ScriptingService] updateHook()

4.111 [ Info   ][ScriptingService] backgroundTask triggered
4.111 [ Info   ][ScriptingService] func3()                  # <-- func3() executes synchronously and calls func2()
4.111 [ Info   ][ScriptingService] backgroundTask triggered # <-- backgroundTask triggered again in the same cycle!!!
4.111 [ Info   ][ScriptingService] func2()
4.111 [ Info   ][ScriptingService]   i = 3

# dead-lock in ExecutionEngine::waitAndProcessFunctions() !!!

toolchain-2.9 with this patch:

0.129 [ Info   ][ScriptingService] Loading Program 'backgroundTask'
0.131 [ Info   ][ScriptingService] Exported Function 'func1' added to task 'test'
0.136 [ Info   ][ScriptingService] Exported Function 'func2' added to task 'test'
0.138 [ Info   ][ScriptingService] Exported Function 'func3' added to task 'test'
0.141 [ Info   ][ScriptingService] func1()                  # <-- func1() executes asynchronously
0.142 [ Info   ][ScriptingService] func2()                  # <-- func2() executes asynchronously
0.142 [ Info   ][ScriptingService]   i = 1                  # <-- func2() yields

1.127 [ Info   ][ScriptingService] backgroundTask triggered
1.128 [ Info   ][ScriptingService]   i = 2                  # <-- func2() continues in the next update cycle and returns
1.128 [ Info   ][ScriptingService] updateHook()
1.132 [ Info   ][ScriptingService] func3()                  # <-- func3() executes asynchronously
1.132 [ Info   ][ScriptingService] func2()                  # <-- func2() called from func3() executes asynchronously
1.132 [ Info   ][ScriptingService]   i = 3                  # <-- yield does not wait for the next cycle (only pending operations would be processed)!
1.132 [ Info   ][ScriptingService]   i = 4
# finished

Non-periodic activity

In case the component would be non-periodic:

master/toolchain-2.8 without this patch:

0.154 [ Info   ][ScriptingService] Loading Program 'backgroundTask'
0.154 [ Warning][ScriptingService] Loading program backgroundTask in a TaskContext with getPeriod() == 0. Use setPeriod(period) in order to setup execution of scripts. If you know what you are doing, you may disable this warning using scripting.ZeroPeriodWarning=false
0.156 [ Info   ][ScriptingService] Exported Function 'func1' added to task 'test'
0.161 [ Info   ][ScriptingService] Exported Function 'func2' added to task 'test'
0.163 [ Info   ][ScriptingService] Exported Function 'func3' added to task 'test'

0.165 [ Info   ][ScriptingService] backgroundTask triggered # <-- start() triggers a full update step
0.165 [ Info   ][ScriptingService] updateHook()

0.166 [ Info   ][ScriptingService] backgroundTask triggered # <-- call of func1() triggers a full update step
0.166 [ Info   ][ScriptingService] func1()
0.166 [ Info   ][ScriptingService] updateHook()

0.167 [ Info   ][ScriptingService] backgroundTask triggered # <-- call of func2() triggers a full update step
0.167 [ Info   ][ScriptingService] func2()
0.167 [ Info   ][ScriptingService]   i = 1                  # <-- func2() yields
0.167 [ Info   ][ScriptingService] updateHook()

# script execution blocks, but another trigger() call would unblock it.

toolchain-2.9 without this patch (as reported in #150):

0.124 [ Info   ][ScriptingService] Loading Program 'backgroundTask'
0.125 [ Warning][ScriptingService] Loading program backgroundTask in a TaskContext with getPeriod() == 0. Use setPeriod(period) in order to setup execution of scripts. If you know what you are doing, you may disable this warning using scripting.ZeroPeriodWarning=false
0.126 [ Info   ][ScriptingService] Exported Function 'func1' added to task 'test'
0.131 [ Info   ][ScriptingService] Exported Function 'func2' added to task 'test'
0.133 [ Info   ][ScriptingService] Exported Function 'func3' added to task 'test'

0.136 [ Info   ][ScriptingService] backgroundTask triggered # <-- start() triggers a full update step
0.136 [ Info   ][ScriptingService] updateHook()

# call of func1() blocks until someone would trigger the component...

toolchain-2.9 with this patch:

0.133 [ Info   ][ScriptingService] Running Script function_test.ops ...
0.138 [ Info   ][ScriptingService] Loading Program 'backgroundTask'
0.138 [ Warning][ScriptingService] Loading program backgroundTask in a TaskContext with getPeriod() == 0. Use setPeriod(period) in order to setup execution of scripts. If you know what you are doing, you may disable this warning using scripting.ZeroPeriodWarning=false
0.139 [ Info   ][ScriptingService] Exported Function 'func1' added to task 'test'
0.146 [ Info   ][ScriptingService] Exported Function 'func2' added to task 'test'
0.148 [ Info   ][ScriptingService] Exported Function 'func3' added to task 'test'

0.151 [ Info   ][ScriptingService] backgroundTask triggered # <-- start() triggers a full update step
0.151 [ Info   ][ScriptingService] updateHook()

0.152 [ Info   ][ScriptingService] func1()                  # <-- func1() executes asynchronously
0.153 [ Info   ][ScriptingService] func2()                  # <-- func2() executes asynchronously
0.153 [ Info   ][ScriptingService]   i = 1                  # <-- func2() yields and is enqueued for synchronous operation

# call of func2() blocks until someone would trigger the component...

For the last case: Should calling a function that yields imply that the executing component is triggered repeatedly (full update steps) until the function is done? That would resolve the situation but might lead to unexpected executions of updateHook(), programs and state machines again. With the current version of this patch there must be a third party that triggers the component. If the function is sent, the caller is not blocked, but in my opinion the behavior should not be different and a yielded function would also require another trigger in this case.

[kevindm]

It would be nice to format this for readability's sake.

[kevindm]

This looks like it is performing as described.
One remark: the current behaviour of 'yield' in a called function (ie. func3 calling func2 above) feels counter-intuitive. What happens when the following gets executed?

void wait() {
  while (some_condition_that_can_only_become_true_async()) {
    yield;
  }
}
void func() {
  print( "initiating wait.\n" );
  wait();
  print( "done waiting.\n" );
}

[meyerj]

Thanks, @kevindm, for your review. I think I addressed most of your comments.

About your example: You are right and the script might block and busy-wait depending on what exactly some_condition_that_can_only_become_true_async() is waiting for. The current solution is a trade-off. Proper support of nested yielding would require a major refactoring of the scripting engine, because each function is represented by a separate FunctionGraph and it does not expect that a normal statement like wait() inside func() can yield or, in other words, that the execution of function func() must be interrupted as a result of calling wait() to do something else in the current thread and then be continued in the next update cycle.

The behavior of that example before this patch and in all versions of RTT 2.x was also ill-defined, because the yield statement in this context only unblocked other yielded functions and executed programs or state machines without waiting for the next update cycle, but did not allow execution of pending operation calls or execute the updateHook(). Additionally, the call of wait() or any other function inside func() had side effects on other functions and state machines currently being loaded and, without the patch in #91, triggered another full update cycle for non-periodic components. So I think it can only get better...

To make another point: What should be expected from

// Orocos scripting
export void wait() {
  while (some_condition_that_can_only_become_true_async()) {
    yield;
  }
}

// C++
void func() {
  log() << "initiating wait." << endlog();
  wait();
  log() << "done waiting." << endlog();
}

if the scripting function wait() needs to be executed by the same thread that is currently executing the C++ function func()? We cannot interrupt a C++ function and continue its execution later either.

Note that yield in Orocos scripting has a completely different (and actually a not well-defined) meaning than yielding in classical multithreaded programming ("give other threads a chance to execute"). So as long as Orocos does not allow a single component to have multiple threads, a "classical" yield would not allow other primitives of the same component to execute at all.

[meyerj]

We could apply the same method as in cab8632 also to other unit tests to improve readability of scripting snippets.

[meyerj]

All test cases in scripting_test.cpp still pass without switching to a true multi-threaded test and using the default Activity, but some problematic effects of nested function calls and yield statements would be hidden if they are executed sequentially by the main thread.

[meyerj]

We could add a warning log output if a called function is yielding and the yield statement is ignored, because that's probably undesired behavior in almost all cases. Same is true for yield statements in scripts outside of functions or programs (cf. ScriptParser.cpp:92).

As a side note: A yield statement is not the only reason why a script/program might return true from ProgramInterface::execute() before being finished and wants to be executed again in the next cycle, e.g. the .cmd() syntax introduced in #84 of if the program is paused. Whenever the term "yield" has been used in the description or comments of this PR, all those cases have to be included.

[meyerj]

Also merged into master in baaea50 after #91.