WaitTimer tag issue

[mistahmikey]

I am experiencing another random problem where WaitTimer does not wait for the specified period. For example, a recent run of the following code:

			<If Condition="IsTimeBetween(21,1)">
				<!-- Nothing to do until 1am Eorzea time, so wait at next aetheryte -->
				<TeleportTo Name="Camp Dragonhead" AetheryteId="23" />
				<MoveTo XYZ="274.5798, 295.1528, -71.25455" Name="Hotspot"/>
				<LogMessage Message= "Waiting until 1am Eorzea Time"/>
				<WaitWhile Condition ="IsTimeBetween(21,1)" />
				<WaitTimer WaitTime="15"/>
			</If>

Produced this log:

[22:46:38.905 N][22:46:03.784 V] [Poi.Clear] Reason: Current behavior changed to TeleportTo: LineNumber: 524, ZoneId: 0, AetheryteId: 23, Name: Camp Dragonhead, Force: False, Aetheryte: null, IsDone: False, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.PrioritySelector, .
[22:46:03.785 D] Replaced hook [ProfileOrderBehavior_Hook] 1b1f845e-8b7c-4db9-aa59-477a03f04341
[22:46:04.066 D] Teleporting to Camp Dragonhead
[22:46:14.992 V] [Poi.Clear] Reason: Current behavior changed to MoveToTag: LineNumber: 525, XYZ: <274.5798, 295.1528, -71.25455>, Name: Hotspot, Distance: 3, UseMesh: True, IsDone: False, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.PrioritySelector, .
[22:46:14.992 D] Replaced hook [ProfileOrderBehavior_Hook] 64c07070-0dc1-4bf4-ac3c-586ef18adcad
[22:46:14.992 D] Requesting path on 155 from <227.7368, 312, -228.9932> to <274.5798, 295.1528, -71.25455>
[22:46:15.017 D] Generated path to <274.5798, 295.1528, -71.25455> in 00:00:00.0254704 ms
[22:46:16.990 D] Moving to next hop: <243.7577, 312.1225, -234.7698> (Hotspot) D: 1.62087
[22:46:17.112 D] Moving to next hop: <243.7712, 312.1471, -233.4276> (Hotspot) D: 1.686587
[22:46:17.236 D] Moving to next hop: <243.6962, 309.0989, -223.0847> (Hotspot) D: 11.28899
[22:46:18.398 D] Moving to next hop: <242.6557, 309.0989, -221.9916> (Hotspot) D: 1.842018
[22:46:18.520 D] Moving to next hop: <233.171, 305.8989, -221.8276> (Hotspot) D: 10.42696
[22:46:19.594 D] Moving to next hop: <232.1961, 305.8989, -221.3383> (Hotspot) D: 1.338542
[22:46:19.660 D] Moving to next hop: <232.0711, 305.8989, -219.8276> (Hotspot) D: 2.001971
[22:46:19.851 D] Moving to next hop: <230.5712, 303.0989, -211.6776> (Hotspot) D: 8.992597
[22:46:20.710 D] Moving to next hop: <232.3076, 302.1597, -207.5852> (Hotspot) D: 5.275818
[22:46:21.198 D] Moving to next hop: <226.6962, 302.6989, -160.4776> (Hotspot) D: 48.09806
[22:46:26.474 D] Moving to next hop: <226.1324, 302.7323, -151.6831> (Hotspot) D: 9.432601
[22:46:27.466 D] Moving to next hop: <226.8324, 301.6197, -142.0831> (Hotspot) D: 10.19365
[22:46:28.509 D] Moving to next hop: <231.8712, 300.6989, -134.8776> (Hotspot) D: 9.500582
[22:46:29.473 D] Moving to next hop: <238.2711, 296.6989, -122.0776> (Hotspot) D: 15.61041
[22:46:31.106 D] Moving to next hop: <263.8712, 294.0989, -90.0776> (Hotspot) D: 41.40343
[22:46:35.654 D] Moving to next hop: <274.5798, 295.1528, -71.25455> (Hotspot) D: 22.06543
[22:46:38.905 V] [Poi.Clear] Reason: Current behavior changed to LogMessageTag: LineNumber: 526, IsDone: False, Message: Waiting until 1am Eorzea Time, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.PrioritySelector, .
[22:46:38.905 D] Replaced hook [ProfileOrderBehavior_Hook] 5edf2505-8f7d-42ce-a5b9-effdbc1dac4b
[22:46:38.905 N] Waiting until 1am Eorzea Time
[22:46:38.962 V] [Poi.Clear] Reason: Current behavior changed to 
: LineNumber: 527, Condition: IsTimeBetween(21,1), Conditional: System.Func`1[System.Boolean], IsDone: False, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.PrioritySelector, .
[22:46:38.962 D] Replaced hook [ProfileOrderBehavior_Hook] dded02c9-766c-488b-a681-df719a9c4664
[22:50:01.153 V] [Poi.Clear] Reason: Current behavior changed to WaitTimerTag: LineNumber: 528, IsDone: False, WaitTime: 15, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.Sequence, .
[22:50:01.153 D] Replaced hook [ProfileOrderBehavior_Hook] fe663488-96d1-4244-8e53-f6c37c22f0b5
[22:52:56.000 V] [Poi.Clear] Reason: Current behavior changed to LogMessageTag: LineNumber: 25, IsDone: False, Message: Mining in Coerthas Central Highlands, HighPriority: False, InCombat: False, QuestId: 0, StepId: 0, PostCombatDelay: 0, QuestName: null, IsDoneCache: False, Behavior: TreeSharp.PrioritySelector, .
[22:52:56.000 D] Replaced hook [ProfileOrderBehavior_Hook] 6fe29c03-c833-4af9-867d-27e26d01e0c2
[22:52:56.000 N] Mining in Coerthas Central Highlands

The script acted as if the timer returned immediately, definitely nowhere near the specified 15 seconds. In fact, the script missed mining the node because it did not pop exactly on the hour so the gather tag failed. I have seen this behavior at other wait points as well.

 

[deflama]

nvm, best of luck finding the solution

 

[mistahmikey]

The orderbot element I posted waits until 1am (which is when the node is supposed to pop, but it usually doesnt show up for 5 seconds or so), THEN it waits the 15 seconds. I use this technique in a variety of places, and for the most part, it works, but every so often that WaitTimer just seems to do nothing. In this particular case, the availability of nodes is such that my script always waits in that element, because there are no other unspoileds to mine during that time. I don't see how there is anything wrong with that logic, but if I am missing some subtlety of how the WaitWhile and WaitTimer tags work, please let me know.

 

[mastahg]

Can you please post the entire profile. I think i might know whats going on.

 

[mistahmikey]

Ok, here you go. By the way, I am still experiencing the random movement hang, also while running this script. Every single time this occurs, all I have to do is move the character forward a wee bit with the keyboard, and the script takes off again. It's also worth noting that my modified Chanko script (also attached) gleefully gobbles food while I am just standing there, so clearly things are not completely frozen. It just seems like your movement code believes the toon has not yet arrived at its destination, even though it is certainly very close to it, and is somehow failing to move the toon forward that final little bit. It would be helpful if you could add a console message when the movement code actually decides it has arrived at its destination - then we would know for sure if what I surmise is true.