Runtime Events Firing Order

RRemDust · 1 مايو 2020

Hi guys,
I would like some clarifications about events firing. I read the docs and I understand that mixing makes it tricky ^^

Right now my problem is this :
Start Event of queued animations fires BEFORE Complete Event of currently played animation.
Is this intended behavior ? :think:

What I'd like to achieve is : Start-Complete-Start-Complete and so on.
What I have is : Start-Start-Complete...

Note : I'm listening to events in trackEntry
Ultimately what I need to achieve is knowing when my badguy actions starts and finish even with queued animations

As always, thank you so much for your awesome support guys :love:

RRemDust · 1 مايو 2020

Nate · 1 مايو 2020

The order for a single animation is:

start
event
event
complete
event
event
complete
event
event
end
dispose

The only event not shown above is interrupt, which happens when another entry has replaced the current entry.

If you are getting multiple start events you must be setting a second animation. Please show your setAnimation and addAnimation calls.

We have tests so we can carefully monitor how any changes to AnimationState affect event timing and order. See this test:
spine-runtimes/AnimationStateTests.java at 3.8
I don't suggest trying to read the test harness code, it's pretty intense. This test does:

state.setAnimation(0, "events0", false);
state.addAnimation(0, "events1", false, 0).setTrackEnd(1);

The order is:

#  EVENT       TRACK  TOTAL
0  start       0      0    

0  event 0     0      0    

0  event 14    0.5    0.5  

0  event 30    1      1    

0  complete    1      1    

0  interrupt   1.1    1.1  

1  start       0.1    1.1  

1  event 0     0.1    1.1  

0  end         1.1    1.2  

0  dispose     1.1    1.2  

1  event 14    0.5    1.5  

1  event 30    1      2    

1  complete    1      2    

1  end         1      2.1  

1  dispose     1      2.1

The # column denotes the animation, 0 for events0 or 1 for events1 (it's not the track number, everything is on track 0 for this test). TRACK and TOTAL are times in seconds for the track entry and for the entire AnimationState.

As you can see, complete for the first animation happens before start for the next animation. That is correct in the spine-libgdx runtime, which is the reference implementation. It should behave the same in spine-unity, if it doesn't it's a bug.

RRemDust · 1 مايو 2020

Thanks you Nate
I'm gonna double check one more time then.

And can you confirm that mixing time doesnt impact the firing order ?

Nate · 1 مايو 2020

It does affect when the events occur (end and dispose of the first animation happen later), but I still don't see complete coming after start. For example, with this code:

state.setAnimation(0, "events0", false);
entry = state.addAnimation(0, "events1", false, 0);
entry.setMixDuration(0.25f);
entry.setTrackEnd(1);

The order is:

#  EVENT       TRACK  TOTAL
0  start       0      0    

0  event 0     0      0    

0  event 14    0.5    0.5  

0  event 30    1      1    

0  complete    1      1    

0  interrupt   1.1    1.1  

1  start       0.1    1.1  

1  event 0     0.1    1.1  

0  end         1.3    1.4  

0  dispose     1.3    1.4  

1  event 14    0.5    1.5  

1  event 30    1      2    

1  complete    1      2    

1  end         1      2.1  

1  dispose     1      2.1

Note the events of the first animation don't fire during mix duration because of TrackEntry eventThreshold.

RRemDust · 2 مايو 2020

So, I hope I'm not mistaken here but these are not my results.

Here is the script I'm running.

private AnimationReferenceAsset currentAnimAsset;
    public AnimationReferenceAsset anim1, anim2, anim3;
    public SpineRootMotion rootMotion;

#region spine Animation State
// Spine.AnimationState and Spine.Skeleton are not Unity-serialized objects. We will not see them as fields in the inspector.
public SkeletonAnimation skeletonAnimation;
public Spine.AnimationState spineAnimationState;
public Spine.Skeleton skeleton;
public Spine.IkConstraint myIkConstraint;
public Spine.TrackEntry trackEntry;
#endregion
// Start is called before the first frame update
void Start()
{
    #region skeletonSettings
    skeletonAnimation = GetComponent<SkeletonAnimation>();
    spineAnimationState = skeletonAnimation.state;
    skeleton = skeletonAnimation.skeleton;
    #endregion

    skeletonAnimation.state.Start += delegate (Spine.TrackEntry entry) // Start of animations ?
    {
        string animName = entry.Animation.Name;
        if (entry.Loop == false)
        {
            Debug.Log("Enemy BUSY entering " + animName);
            ActivateRootMotion(); 
        }
        else
        {
            DisactivateRootMotion();
        }
    };

    skeletonAnimation.state.Complete += delegate (Spine.TrackEntry entry) // End of animations ?
    {
        string animName = entry.Animation.Name;
        if (entry.Loop == false) 
        {
            Debug.Log("ENEMY NOT BUSY ANYMORE from " + animName);
            if (entry.Next == null)
            {
                //
            }
        }
    };

    AddAnimationAsset(anim1);
    AddAnimationAsset(anim2);
    AddAnimationAsset(anim3);
}

public void AddAnimationAsset(AnimationReferenceAsset asset)
{
    Debug.Log("we queue " + asset.name);
    trackEntry = skeletonAnimation.state.AddAnimation(0, asset, asset.isLoop, 0);

    if (asset.isLoop)
    {
        //
    }
    else
    {
        //
    }
}

public void ActivateRootMotion()
{
    rootMotion.enabled = true;
}

public void DisactivateRootMotion()
{
    rootMotion.enabled = false;
}
}

And here is my console :

I'm puzzled here ! Please tell me I'm missing something obvious (it wouldnt be the first time... )
:think:

[EDIT] I don't know why I haven't tried before but setting the mix value to 0 FIXES THE PROBLEM.
Now is this "normal" ? And if yes What should I do to get the callbacks I wanted in the first place ?
Bonus : Not sure it this is the right place to enable/unable root motion as long as events note fire properly ^^
Thanks Nate

Nate · 2 مايو 2020

RemDust, what have you done!? My eyes! Braces go on the same line! :yuno:

Getting past that, it'd be nice if we could run the code to see the output, but it looks like your test code is OK. We'll create our own similar test harness with spine-unity that we can run and check if we see the behavior not matching the reference implementation. Harri is out for his weekend shenanigans but early next week he can dig into, depending on the other work he has going on.

RRemDust · 2 مايو 2020

Nate wrote
RemDust, what have you done!? My eyes! Braces go on the same line! :yuno:

:rofl: I had troubles with VisualStudio and Intellisense switching on my new mac :lol:
Hopefully my lovely diagram will save the day :shh:

Getting past that, I ended up removing all animation mixing for the time being
In the meantime I'm exploring AnimationReferenceAsset and expanding on it is really cool

Please let me know when you'll have your own tests running
Have a nice one :beer:

Harald · 4 مايو 2020

FYI: I will be able to create a test setup tomorrow, as todays work kept me busy longer than expected (and the dentist took part of my work time as well ).

RRemDust · 4 مايو 2020

Harald wrote
FYI: I will be able to create a test setup tomorrow, as todays work kept me busy longer than expected (and the dentist took part of my work time as well ).

Don't worry Harald !
Thank you so much for your help, again :clap:

Harald · 5 مايو 2020

The AnimationState tests have been ported to csharp and all run, they all pass as expected.

However, when I use non-fixed time increments and let the code

state.SetAnimation(0, "events0", false);
var entry = state.AddAnimation(0, "events1", false, 0);
entry.MixDuration = 0.25f;
entry.TrackEnd = 1.0f;

run in a Unity "real life scenario" on a SkeletonAnimation component, I receive the following output:

#  EVENT       TRACK  TOTAL  (note that Total time is not precise here as it uses Unity's Time.time for convenience)
0  start       0.000  0.000  

0  event 0     0.020  0.000  

0  event 14    0.475  0.455  

0  interrupt   0.814  0.794     //<

---

 here a transition is started
1  start       0.014  0.794  

1  event 0     0.014  0.794  

0  complete    1.003  0.983    //<

---

 here the transition is ended and animation 0 is complete
0  end         1.058  1.048  

0  dispose     1.058  1.048  

1  event 14    0.472  1.252  

1  event 30    1.005  1.785  

1  complete    1.005  1.785  

1  end         1.005  1.797  

1  dispose     1.005  1.797

Actually this would be the expected outcome from my perspective, as the MixDuration of 0.25 starts the interruption at 0.814 (seems to have been the next frame after time 0.75), and starts a transition there. It ends the transition at 1.003 and also completes animation 0.

In short: When transitions are active and you want to receive callbacks upon starting the transition and not it's end, I think what you want instead of only listening to Complete is that you would listen to both Complete and Interrupt and trigger at any of the two, whatever comes first.

RRemDust · 5 مايو 2020

I see, this is expected behavior as complete/end both raise when the animation starts mixing into the next.
What I need is not this moment but the actual end of the animation

Can I create a custom event in the editor to create my own "end anim event" or will it be lost in the mixing time as well ?

Nate · 5 مايو 2020

RemDust wrote
this is expected behavior as complete/end both raise when the animation starts mixing into the next

That is not an accurate statement for either event.

complete Invoked every time this entry's animation completes a loop.
end Invoked when this entry is no longer the current entry and will never be applied again.
That is exactly when the events occur.

When you queue animations like this:

state.SetAnimation(0, "events0", false);
var entry = state.AddAnimation(0, "events1", false, 0);
entry.MixDuration = 0.25f;

The second 0 in the second line starts mixing in the events1 animation 0.25s (the mix duration) before the end of the event0 animation (see the addAnimation delay parameter docs). That is why you see the events1 start event before the events0 complete event. The complete event happens even during mixing out.

It sounds like the complete event is not what you want. It only tells you when an animation completes a loop. You should use the other events as Harri explained.

Can I create a custom event in the editor to create my own "end anim event" or will it be lost in the mixing time as well ?

You mean to use an event timeline? A key on the last frame of the animation would fire at exactly the same time as the complete event.

RRemDust · 7 مايو 2020

Thanks for the detailed answer, after a good night sleep it was easier to understand
My error was that I expected this order "end or complete then start" when Mixing implies that start event will always fires BEFORE complete/end of previous animation.

Interrupt seems to be the callback I should use