OnUpdate () and State bugs(?) : V

» Tue Jun 19, 2012 7:33 pm

Is anyone else finding major bugs with OnUpdate (). After a day of coding, I'm finding weird things with Onupdate ().
Here's a log of a normal iteration of an OnUpdate ():

Spoiler

I add two items to the queue:

[[02/25/2012 - 10:32:25PM] !kuiawqs.addItem 1 x [Armor < (0003C9FE)>] to 0[02/25/2012 - 10:32:25PM] !kuiawqs.addItem 1 x [Armor < (0003CA00)>] to 1

Notice these two blocks:
An item gets added, it's weight is found, then it is removed.
In the 1st block, Armor 0003C9FE is processed.

----------new OnUpdate ()[02/25/2012 - 10:32:26PM] !kuiawqs.tick [Armor < (0003C9FE)>][02/25/2012 - 10:32:26PM] !kuiawqs.tick AddItem 1 x [Armor < (0003C9FE)>] from 0----------new OnUpdate ()[02/25/2012 - 10:32:27PM] !kuiawqs.tick checking item [Armor < (0003C9FE)>] from 0[02/25/2012 - 10:32:27PM] !kuiawqs.tick found weight [Armor < (0003C9FE)>] 1.000000 at 0 from 0[02/25/2012 - 10:32:27PM] !kuiawqs.tick RemoveItem [Armor < (0003C9FE)>] from 0

In the 2nd block, Armor 0003CA00 is processed.

----------new OnUpdate ()[02/25/2012 - 10:32:27PM] !kuiawqs.tick [Armor < (0003CA00)>][02/25/2012 - 10:32:27PM] !kuiawqs.tick AddItem 1 x [Armor < (0003CA00)>] from 1----------new OnUpdate ()[02/25/2012 - 10:32:27PM] !kuiawqs.tick checking item [Armor < (0003CA00)>] from 1[02/25/2012 - 10:32:27PM] !kuiawqs.tick found weight [Armor < (0003CA00)>] 1.000000 at 1 from 1[02/25/2012 - 10:32:27PM] !kuiawqs.tick RemoveItem [Armor < (0003CA00)>] from 1----------new OnUpdate ()[02/25/2012 - 10:32:27PM] !kuiawqs.tick None[02/25/2012 - 10:32:27PM] !kuiawqs.tick all added. clean.

When done, the queue of items to add is cleaned-up and the OnUpdate () waits for new items to appear in the list.

Here's another correctly working OnUpdate () processing a potion:

Spoiler

----------new OnUpdate ()[02/25/2012 - 10:34:38PM] !kuiawqs.addItem 1 x [Potion < (0003EADD)>] to 0----------new OnUpdate ()[02/25/2012 - 10:34:38PM] !kuiawqs.tick [Potion < (0003EADD)>][02/25/2012 - 10:34:38PM] !kuiawqs.tick AddItem 1 x [Potion < (0003EADD)>] from 0----------new OnUpdate ()[02/25/2012 - 10:34:38PM] !kuiawqs.tick checking item [Potion < (0003EADD)>] from 0[02/25/2012 - 10:34:38PM] !kuiawqs.tick found weight [Potion < (0003EADD)>] 0.500000 at 0 from 0[02/25/2012 - 10:34:39PM] !kuiawqs.tick RemoveItem [Potion < (0003EADD)>] from 0[02/25/2012 - 10:34:39PM] !kuiawqs.tick None[02/25/2012 - 10:34:39PM] !kuiawqs.tick all added. clean.

So, when working normally, the order of debug traces are:

Spoiler

OnUpdate ()!kuiawqs.tick AddItemOnUpdate ()!kuiawqs.tick checking item!kuiawqs.tick found weight!kuiawqs.tick RemoveItem

Here's a weird iteration:

Spoiler

----------new OnUpdate ()[02/25/2012 - 11:05:38PM] !kuiawqs.addItem 1 x [WEAPON < (00013790)>] to 0[02/25/2012 - 11:05:38PM] !kuiawqs.addItem 1 x [Form < (000A6D7B)>] to 1[02/25/2012 - 11:05:38PM] !kuiawqs.addItem 1 x [Form < (000A6D7F)>] to 2----------new OnUpdate ()[02/25/2012 - 11:05:39PM] !kuiawqs.tick [WEAPON < (00013790)>][02/25/2012 - 11:05:39PM] !kuiawqs.tick AddItem 1 x [WEAPON < (00013790)>] from 0----------new OnUpdate ()[02/25/2012 - 11:05:39PM] !kuiawqs.tick checking item [WEAPON < (00013790)>] from 0[02/25/2012 - 11:05:39PM] !kuiawqs.tick found weight [WEAPON < (00013790)>] 11.000000 at 2 from 0

When working correctly, immediately after "!kuiawqs.tick found weight" should be: "!kuiawqs.tick RemoveItem".
But as shown below, an OnUpdate () is triggered. Then immediately after that the "!kuiawqs.tick RemoveItem" line.
What seems to have happened is that a new OnUpdate () iteration was triggered while the previous OnUpdate () was getting processed.

----------new OnUpdate ()[02/25/2012 - 11:05:39PM] !kuiawqs.tick [WEAPON < (00013790)>][02/25/2012 - 11:05:39PM] !kuiawqs.tick RemoveItem [WEAPON < (00013790)>] from 0[02/25/2012 - 11:05:39PM] !kuiawqs.tick AddItem 1 x [WEAPON < (00013790)>] from 1----------new OnUpdate ()[02/25/2012 - 11:05:39PM] !kuiawqs.tick checking item [Form < (000A6D7B)>] from 1[02/25/2012 - 11:05:39PM] !kuiawqs.tick found weight [Form < (000A6D7B)>] 11.000000 at 3 from 1[02/25/2012 - 11:05:39PM] !kuiawqs.tick RemoveItem [Form < (000A6D7B)>] from 1

The result in this code is that Weapon 00013790 is processed twice (note "AddItem 1 x [WEAPON < (00013790)>]" twice above) and out of order.
Data in my mod is then corrupt.

Ok...OnUpdate () firing before the previous OnUpdate () code is finished, I can manage.
I can understand if Skyrim's interval manager simply triggers OnUpdate () at the requested interval regardless of the status of the previous OnUpdate () - i.e. it failed, it takes too long, it didn't complete, etc...

However, (and here is where it really is F'ed!)
these lines run in 2 states: one that adds the item and the other that checks for its weight and then removes it.
Even if an OnUpdate () executed while the previous OnUpdate () process was still running,
the State the Script was on should have prevented it from processing the same item twice.

Anyone else finding weird OnUpdate () and States bugs?

» Tue Jun 19, 2012 6:49 am

Confirmed. OnUpdate () does execute regardless of the state of the previous OnUpdate ().
For scripts with a very high interval (e.g. RegisterForUpdate (0.01)), OnUpdate () will run over each iteration.
My solution is to add a "busy" flag and have the Script only run when it it is False.
E.g.:

Event OnInit ()    RegisterForUpdate (0.01)EndEventBool busyEvent OnUpdate ()    If !busy        busy = True        ;...do stuff here        busy = False    EndIfEndEvent

Spoiler

For those with the keener senses, this doesn't really solve my problem of how my Script ignored its States in my previous post.
Well, it actually wasn't ignored. The problem with my previous code was that I was change the States at the beginning of its process.
i.e.:

State state2    GoToState ("state1")    ;...do my stuffEndState

So when OnUpdate () was executed again, even if state2 wasn't complete, it ran state1.

Whew! Modding continues.