Synchronization problems in a Sequence - skips ahead

I’ve got case where I’ve pre-built some AnimationBuilders, and I’m selecting a random builder, fetching it, getting the configured animation duration from the builder, and using this as a timeout while the builder plays.

In a Sequence there is an ExecuteScript that gets the builder and puts it in the notepad, gets the configured duration and puts that in the notepad, then calls play on the builder.

This is followed by a TimeoutJS that should return a time based on the delay stored in the notepad. But the TimeoutJS keeps starting before the builder has finished fetching and setting the delays.

I’ve tried four things:

  1. What I described above. Set notepad.delay from the builder duration. When I get to the TimeoutJS, notepad.delay is undefined.

  2. Just set notepad.builder in the ExecuteScript, and put the call to getConfiguredAnimationDuration in the TimeoutJS. This fails because notepad.builder is undefined.

  3. Set a StartOnCondition decorator on TimeoutJS with a condition of ‘return notepad.builder’, so theoretically the TimeoutJS should not even start until notepad.builder is defined. But it starts anyway, and crashes because notepad.builder is not defined.

  4. Set a SucceedOnCondition decorator on the ExecuteScript with a condition of ‘return notepad.builder’; No change.

My code with this issue is at GitHub chrooke/jibo-knock-knock/tree/sync-problems
The BT with the issue is behaviors/attitudes/react.bt.

SDK: 1.2.7
jibo module: 2.0.5
behviorify module: 1.0.0

I’m adding on to this. I think there really might be an SDK bug here, or at least some undocumented behavior. I’ve reproduced the problem independent of any crazy AnimationBuilder stuff described above. Reduced it to bare bones, and I still see the issue.

I’ve made a simpler BT with three behaviors in a sequence, two ExecuteScripts followed by a TimeoutJs. The two ExecuteScripts each contain a console.log with a sequential number, i.e. ‘1’,‘2’. The TimeoutJs contains a console.log with ‘timeout’, followed by a return 4000;

My output is:

timeout
1
2
<then a 4 second delay>
Behavior tree finished with status SUCCEEDED.

According to the API, “Sequence Runs its child nodes in sequence until one fails.” It doesn’t look like that’s what’s happening here. I consistently see the TimeoutJS running first. I don’t see anything in the TimeoutJS docs to indicate that it wouldn’t behave sequentially.

As before, attempting to delay the start of the TimeoutJS with an event emitted by the second ExecuteScript, or a condition set by the second ExecuteScript, has no effect. The TimeoutJS always starts first.

I just put together the following quick test of 3 behaviors in sequence:

ExecuteScript

console.log("first");

TimeoutJS

return 5000;

ExecuteScript

console.log("second");

It worked as expected, displaying “first” in the console, waiting 5 seconds, then displaying “second” in the console. Then, when I updated the TimeoutJS to log to the console:

console.log("timeout");
return 5000;

…I noticed that the output was:

timeout
first
second

I’m assuming that some processing is taking place in the TimeoutJS beforehand, but the timeout is still occurring in realtime when the skill runs. To test this, I updated the scripts to the following:

ExecuteScript

notepad.test = "first";
console.log(notepad.timeout);

TimeoutJS

console.log(notepad.timeout);
notepad.timeout = "timeout";
return 5000;

ExecuteScript

console.log(notepad.timeout);

Interestingly enough, the output was:

undefined
timeout
timeout

That means that the TimeoutJS ran first even though it was second in the sequence, outputted undefined (since notepad.timeout was not yet defined), then set notepad.timeout to “timeout”, and finally ran the sequence in order.

I would say that this is a bug since it is displaying unexpected results. I would suggest placing no additional code in a TimeoutJS other than the return call until this gets fixed.

Hi Chris, thank you for the added detail above!

Michael, thank you as well for boiling down some steps to reproduce what you/Chris are seeing.

Would one of you mind uploading one of the .bt files you created to test this? I am seeing something a little different when I recreate your steps on my end.

Michael, when I run your second example (with the added console.log("timeout"); ) where you got:

timeout
first
second

I got the following in console:

FIRST
timeout
SECOND

Which is what I would expect to see if things were working as they should. To make sure I have accurately recreated that test I am uploading the .bt I created for that here: main-time-test.bt (1.5 KB)

When I tested your final example, Michael, I got the following:

undefined
undefined
timeout

Which, again, is what I would expect since notepad.timeout doesn’t get set to “timeout” until after your first two console.log lines. Again, for reference, here’s the .bt I used to test: second-time-test.bt (1.6 KB)

Because you are both seeing similar odd behavior it sounds like something is possibly going on that shouldn’t be. If you could take a look at my .bt files and let me know if they look like what you were testing or if you could post your test .bt files I can run those on my end as well.

(On a related note, we just updated our forum settings to allow for direct uploading of .bt files if that’s easiest for you!)

Thank you!

I think I see what is going on here!

To confirm, do both of you have your jibo module set to 2.0.5?

If so, could you please change that in your skill’s package.json to be the following:

"jibo": "^2.0.0"

And then run npm install in your terminal/command line when in the top level directory for your skill.

After doing that could you simulate the above again and let me know if you are still seeing the same behavior?

(My current theory is that we should recommend the use of that fuzzy versioning ("^2.0.0") in our docs for updating a skill after a version update.

If you could confirm that I think it will hopefully take care of this for you and allow us to confirm whether we should update our directions in that fashion.

Thank you again!

My package.json already has “jibo”: “^2.0.0”. The actual module is 2.0.5.

Hi Chris, thank you for confirming that. With that info in mind I did a full clean install/behavior tree and I am now able to reliably reproduce the behavior you have both been seeing.

I have made sure the SDK team has seen that and we’re working on a fix for that which we hope to have in the tool soon. Thank you for your patience while I reproduced that!

No problem. In addition to it kicking off early, it seems a timeout in a while only executes the code before the return once. You can see this if you throw console.log statements in sample-code bt 6 (I think it’s 6, one-shot-LookAt.) Put console.logs in the LookAt and TimeoutJS, and you’ll see the LookAt logs over and over, but the TimeoutJS once.

If anyone needs a workaround in the meantime, I found I could get the effect I wanted by putting my TimeoutJS into a Subtree, and send the delay in as an argument to the Subtree.

1 Like

When I ran these on a brand new project created from Jibo->New Project, I got:

main-time-test.bt

timeout
FIRST
SECOND

second-time-test.bt

undefined
timeout
timeout

Note in the second one, my timeout got defined before the console.log that immediately preceded it.

And here are three .bt files from me.

timeout-alone.bt (1.8 KB)

This is like the others, two ExecuteScripts, a TimeoutJS, and another ExecuteScript. When I run it I get:

timeout
1
2
3

Next: timeout-sequences.bt (2.6 KB) I thought breaking the timeout to a different sequence might help, so I have a Sequence with the first two ExecuteScripts, then a second Sequence with the TimeoutJS and the third ExecuteScript. Same results as the first.

Finally: timeout-loop.bt (1.5 KB) The root Sequence has a While decorator that just returns true. Inside is one ExecuteScript, followed by a TimeoutJs. Output is:

timeout
1
1
1

Again, I created all three of these on a new Jibo project, so there should be no upgrade issues.

package.json shows the following:

“dependencies”: {
“behaviorify”: “^1.0.0”,
“jibo”: “^2.0.0”
},

jibo module is actually at 2.0.5.
jibo-sdk atom package is at 1.2.7.

Hi Chris,

Thank you again for doing some extra testing around this, I’ve provided the extra detail to the team. As Michael noted above, this is a bug and one that the team is now aware of. We will have a fix in place in the SDK as soon as possible.

I have also tested the workaround you mentioned above where the TimeoutJs is placed in a subtree and I am seeing that do the trick.

I agree that using that method will be the best workaround until our team gets this patched up.

Thank you again for all of your input on this!

It looks like this got fixed in SDK 1.3.3. I threw away all my subtree workarounds, and my skills are working fine. When I do an "execute-timeout-execute’ with a console at the beginning of each one, I get the expected “first-timeout-second” sequence. If I run a loop and increase the delay with each pass through the loop, the delay gets longer and longer, as expected. And, yes, with a prebuilt animation builder stored in notepad.builder I can use return notepad.builder.getConfiguredAnimationDuration()*1000; in my TimeoutJS and it works properly.

1 Like

Just wanted to also say that the SDK 1.3.3 release fixed this issue for me. Thanks Jibo team!