StartCrafting() Exception

I've been trying to find the cause of an injection exception I get when using the StartCrafting() method of the Synthesize tag. I'm hoping someone can give me an idea of what might be causing this exception, in the hopes of further testing. It happens rarely, and I have yet to find a pattern. I cannot reproduce it on purpose, and happens around once every 50 different crafted items or so. It only happens the first time a different recipe is crafted; subsequent repetitions of the same recipe have no problem. Today I managed to catch it on tape after leaving it overnight crafting a myriad of items. It only happened once in the entire 6 hour run.

It happens after the Hardsilver Nugget and when trying to start the Fang Earrings.

Video

Notice that the recipe is known, the job is correct, and I check that CraftingManager.AnimationLocked is false before attempting StartCrafting(). Something interesting is that CraftingManager.CanCraft was false right before the exception was thrown, but on the next attempt it was also false and had no problems starting. I'm really lost on what it could be, and since the occurrence is rare it's hard to test.

This is the relevant part of the log:

Code:

[20:44:45.214 N] [Lisbeth] Starting craft order for Hardsilver Nugget x1.
[20:44:45.214 N] [Lisbeth] Moving to your assigned craft location.
[20:44:45.497 N] Building Actioncache
[20:44:45.500 N] Action Name:Sprint Action Id:3
[20:44:45.500 N] Action Name:Steady Hand Action Id:247
[20:44:45.500 N] Action Name:Inner Quiet Action Id:255
[20:44:45.500 N] Action Name:Great Strides Action Id:263
[20:44:45.500 N] Action Name:Manipulation Action Id:278
[20:44:45.500 N] Action Name:Innovation Action Id:284
[20:44:45.500 N] Action Name:Collectable Synthesis Action Id:4563
[20:44:45.500 N] Action Name:Basic Synthesis Action Id:100075
[20:44:45.500 N] Action Name:Basic Touch Action Id:100076
[20:44:45.500 N] Action Name:Master's Mend Action Id:100077
[20:44:45.500 N] Action Name:Standard Touch Action Id:100078
[20:44:45.500 N] Action Name:Master's Mend II Action Id:100079
[20:44:45.500 N] Action Name:Standard Synthesis Action Id:100080
[20:44:45.500 N] Action Name:Advanced Touch Action Id:100081
[20:44:45.500 N] Action Name:Observe Action Id:100082
[20:44:45.500 N] Action Name:Flawless Synthesis Action Id:100083
[20:44:45.500 N] Action Name:Byregot's Brow Action Id:100123
[20:44:45.500 N] Action Name:Precise Touch Action Id:100131
[20:44:45.500 N] Action Name:Innovative Touch Action Id:100140
[20:44:45.500 N] Action Name:Byregot's Miracle Action Id:100148
[20:44:45.500 N] Action Name:Nymeia's Wheel Action Id:100156
[20:44:45.500 N] Action Name:Trained Hand Action Id:100164
[20:44:45.500 N] Action Name:Satisfaction Action Id:100172
[20:44:45.500 N] Action Name:Maker's Mark Action Id:100178
[20:44:45.500 N] Action Name:Heart of the Goldsmith Action Id:100182
[20:44:45.500 N] Action Name:Whistle While You Work Action Id:100190
[20:44:45.500 N] Action Name:Careful Synthesis II Action Id:100069
[20:44:45.500 N] Action Name:Hasty Touch Action Id:100108
[20:44:45.500 N] Action Name:Steady Hand II Action Id:281
[20:44:45.500 N] Action Name:Byregot's Blessing Action Id:100009
[20:44:45.500 N] Action Name:Tricks of the Trade Action Id:100098
[20:44:45.500 N] Action Name:Comfort Zone Action Id:286
[20:44:45.500 N] Action Name:Piece by Piece Action Id:100039
[20:44:45.500 N] Done building Actioncache
[20:44:45.500 N] [Ultima] Loading: Goldsmith
[20:44:47.651 N] [Lisbeth] Setting the recipe. AL: False | LO: False | CC: False
[20:44:50.090 N] [Synthesize] Crafting Hardsilver Nugget (12520) via 2528
[20:44:51.654 N] [Lisbeth] Estimated Gains P: 0 Q: 282
[20:44:51.654 N] [Lisbeth] Using Serenade.
[20:44:51.654 N] [Lisbeth] Calibrating.
[20:44:51.655 N] [Lisbeth] Using CarefulSynthesis2.
[20:44:51.788 D] DoAction CraftAction 100069 0x1057182B
[20:44:54.353 N] [Lisbeth] Added CarefulSynthesis2's progress of 281 to the model.
[20:44:54.353 N] [Lisbeth] Finished calibrating.
[20:44:54.387 N] [Lisbeth] Using ComfortZone.
[20:44:54.489 D] DoAction Spell 286 0x1057182B
[20:44:56.085 N] [Lisbeth] Using InnerQuiet.
[20:44:56.217 D] DoAction Spell 255 0x1057182B
[20:44:57.787 N] [Lisbeth] Using TricksOfTheTrade.
[20:44:57.889 D] DoAction CraftAction 100098 0x1057182B
[20:45:00.554 N] [Lisbeth] Using SteadyHand2.
[20:45:00.688 D] DoAction Spell 281 0x1057182B
[20:45:02.248 N] [Lisbeth] Using HastyTouch.
[20:45:02.390 D] DoAction CraftAction 100108 0x1057182B
[20:45:04.994 N] [Lisbeth] Using TricksOfTheTrade.
[20:45:05.124 D] DoAction CraftAction 100098 0x1057182B
[20:45:07.718 N] [Lisbeth] Using Manipulation.
[20:45:07.847 D] DoAction Spell 278 0x1057182B
[20:45:09.448 N] [Lisbeth] Using HastyTouch.
[20:45:09.551 D] DoAction CraftAction 100108 0x1057182B
[20:45:12.119 N] [Lisbeth] Using PreciseTouch.
[20:45:12.221 D] DoAction CraftAction 100131 0x1057182B
[20:45:14.818 N] [Lisbeth] Using SteadyHand2.
[20:45:14.954 D] DoAction Spell 281 0x1057182B
[20:45:16.523 N] [Lisbeth] Using HastyTouch.
[20:45:16.647 D] DoAction CraftAction 100108 0x1057182B
[20:45:19.223 N] [Lisbeth] Using Manipulation.
[20:45:19.356 D] DoAction Spell 278 0x1057182B
[20:45:20.955 N] [Lisbeth] Using PreciseTouch.
[20:45:21.088 D] DoAction CraftAction 100131 0x1057182B
[20:45:23.652 N] [Lisbeth] Using HastyTouch.
[20:45:23.754 D] DoAction CraftAction 100108 0x1057182B
[20:45:26.353 N] [Lisbeth] Using HastyTouch.
[20:45:26.485 D] DoAction CraftAction 100108 0x1057182B
[20:45:29.153 N] [Lisbeth] Using CarefulSynthesis2.
[20:45:29.285 D] DoAction CraftAction 100069 0x1057182B
[20:45:34.555 N] [Lisbeth] Saving 522 calibrations.
[20:45:35.116 N] [Lisbeth] Starting craft order for Dragon Fang Earrings x1.
[20:45:35.116 N] [Lisbeth] Moving to your assigned craft location.
[20:45:36.215 N] [Lisbeth] Setting the recipe. AL: False | LO: True | CC: False
[20:45:36.256 D] Buddy.Coroutines.CoroutineUnhandledException: Exception was thrown by coroutine ---> GreyMagic.InjectionSEHException: Injection resulted in a process exception with error code 0xc0000005
   at GreyMagic.Executor.WaitForInjection(Int32 timeout)
   at GreyMagic.Executor.SharedExecuteLogicEnd(Int32 timeout)
   at GreyMagic.Executor.Execute(Int32 timeout)
   at GreyMagic.ExternalProcessMemory.CallInjected[T](IntPtr address, CallingConvention callingConvention, Object[] args)
   at ..()
   at ff14bot.Managers.CraftingManager.get_CurrentRecipeId()
   at ff14bot.Managers.CraftingManager.
.
()
   at Buddy.Coroutines.Coroutine.<InternalWait>d__44.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at ff14bot.Managers.CraftingManager..
()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at ff14bot.NeoProfiles.Tags.Synthesize.
.
()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.Crafting.<SetRecipe>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.Crafting.<Craft>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Lisbeth.Reborn.OrderProcessor.<Process>d__23.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.OrderProcessor.<MainRoutine>d__18.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at TreeSharp.ActionRunCoroutine.
.
.
.
()
   --- End of inner exception stack trace ---
   at Buddy.Coroutines.Coroutine.CheckPostConditions(Boolean shouldBeCanceled)
   at Buddy.Coroutines.Coroutine.Resume(Boolean forStop)
   at Buddy.Coroutines.Coroutine.Resume()
   at TreeSharp.ActionRunCoroutine.Run(Object context)
   at TreeSharp.Action.RunAction(Object context)
   at TreeSharp.Action.<Execute>d__0.MoveNext()
   at TreeSharp.Composite.Tick(Object context)
   at ff14bot.TreeRoot.() --> GreyMagic.InjectionSEHException: Injection resulted in a process exception with error code 0xc0000005
   at GreyMagic.Executor.WaitForInjection(Int32 timeout)
   at GreyMagic.Executor.SharedExecuteLogicEnd(Int32 timeout)
   at GreyMagic.Executor.Execute(Int32 timeout)
   at GreyMagic.ExternalProcessMemory.CallInjected[T](IntPtr address, CallingConvention callingConvention, Object[] args)
   at ..()
   at ff14bot.Managers.CraftingManager.get_CurrentRecipeId()
   at ff14bot.Managers.CraftingManager.
.
()
   at Buddy.Coroutines.Coroutine.<InternalWait>d__44.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at ff14bot.Managers.CraftingManager..
()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at ff14bot.NeoProfiles.Tags.Synthesize.
.
()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.Crafting.<SetRecipe>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.Crafting.<Craft>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Lisbeth.Reborn.OrderProcessor.<Process>d__23.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Lisbeth.Reborn.OrderProcessor.<MainRoutine>d__18.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at TreeSharp.ActionRunCoroutine.
.
.
.
()
[20:45:36.292 N] [Lisbeth] Starting craft order for Dragon Fang Earrings x1.
[20:45:36.292 N] [Lisbeth] Moving to your assigned craft location.
[20:45:37.414 N] [Lisbeth] Setting the recipe. AL: False | LO: True | CC: False
[20:45:39.317 N] [Synthesize] Crafting Dragon Fang Earrings (12018) via 2523
[20:45:40.819 N] [Lisbeth] Estimated Gains P: 0 Q: 282
[20:45:40.819 N] [Lisbeth] Using Serenade.
[20:45:40.819 N] [Lisbeth] Calibrating.
[20:45:40.820 N] [Lisbeth] Using CarefulSynthesis2.
[20:45:40.923 D] DoAction CraftAction 100069 0x1057182B
[20:45:43.488 N] [Lisbeth] Added CarefulSynthesis2's progress of 261 to the model.
[20:45:43.488 N] [Lisbeth] Finished calibrating.
[20:45:43.516 N] [Lisbeth] Using ComfortZone.
[20:45:43.617 D] DoAction Spell 286 0x1057182B
[20:45:45.023 N] [Lisbeth] Using InnerQuiet.
[20:45:45.150 D] DoAction Spell 255 0x1057182B
[20:45:46.793 N] [Lisbeth] Using CarefulSynthesis2.
[20:45:46.924 D] DoAction CraftAction 100069 0x1057182B
[20:45:49.887 N] [Lisbeth] Using TricksOfTheTrade.
[20:45:50.017 D] DoAction CraftAction 100098 0x1057182B
[20:45:52.621 N] [Lisbeth] Using SteadyHand2.
[20:45:52.722 D] DoAction Spell 281 0x1057182B
[20:45:54.314 N] [Lisbeth] Using PreciseTouch.
[20:45:54.421 D] DoAction CraftAction 100131 0x1057182B
[20:45:56.991 N] [Lisbeth] Using HastyTouch.
[20:45:57.117 D] DoAction CraftAction 100108 0x1057182B
[20:45:59.887 N] [Lisbeth] Using HastyTouch.
[20:45:59.990 D] DoAction CraftAction 100108 0x1057182B
[20:46:02.561 N] [Lisbeth] Using Manipulation.
[20:46:02.686 D] DoAction Spell 278 0x1057182B
[20:46:04.290 N] [Lisbeth] Using HastyTouch.
[20:46:04.414 D] DoAction CraftAction 100108 0x1057182B
[20:46:06.988 N] [Lisbeth] Using SteadyHand2.
[20:46:07.091 D] DoAction Spell 281 0x1057182B
[20:46:08.688 N] [Lisbeth] Using HastyTouch.
[20:46:08.817 D] DoAction CraftAction 100108 0x1057182B
[20:46:11.388 N] [Lisbeth] Using HastyTouch.
[20:46:11.492 D] DoAction CraftAction 100108 0x1057182B
[20:46:14.090 N] [Lisbeth] Using Manipulation.
[20:46:14.214 D] DoAction Spell 278 0x1057182B
[20:46:15.818 N] [Lisbeth] Using HastyTouch.
[20:46:15.952 D] DoAction CraftAction 100108 0x1057182B
[20:46:18.525 N] [Lisbeth] Using HastyTouch.
[20:46:18.652 D] DoAction CraftAction 100108 0x1057182B
[20:46:21.218 N] [Lisbeth] Using SteadyHand2.
[20:46:21.321 D] DoAction Spell 281 0x1057182B
[20:46:22.885 N] [Lisbeth] Using HastyTouch.
[20:46:22.990 D] DoAction CraftAction 100108 0x1057182B
[20:46:25.752 N] [Lisbeth] Using Manipulation.
[20:46:25.854 D] DoAction Spell 278 0x1057182B
[20:46:27.454 N] [Lisbeth] Using HastyTouch.
[20:46:27.588 D] DoAction CraftAction 100108 0x1057182B
[20:46:30.222 N] [Lisbeth] Using CarefulSynthesis2.
[20:46:30.353 D] DoAction CraftAction 100069 0x1057182B
[20:46:36.420 N] [Lisbeth] Saving 523 calibrations.
[20:46:39.286 N] [Lisbeth] Starting craft order for Crawler Silk x1.
[20:46:39.286 N] [Lisbeth] Moving to your assigned craft location.

Any help is very much appreciated.

 

The bug has to do with
public static async Task<bool> SetRecipe(uint recipeId)

It always throws this error if it tries to set the recipe to recipeId when you have already selected this recipe.... Every time. Don't believe me, try this code snippet in your RebornConsole.

Hardsilver Nugget:

Code:

var coroutine = new Buddy.Coroutines.Coroutine(() => CraftingManager.SetRecipe(2528));

while(!coroutine.IsFinished)
{
Thread.Sleep(33);
coroutine.Resume();
}

Even better.... try this. This will give you an error for sure if the Crafting log is open. If it is not open, it will just open the crafting log, and not change the recipe.

Code:

var coroutine = new Buddy.Coroutines.Coroutine(() => CraftingManager.SetRecipe(CraftingManager.CurrentRecipeId));

while(!coroutine.IsFinished)
{
Thread.Sleep(33);
coroutine.Resume();
}

Now....

Calling Synthesize.StartCrafting() must make a call to CraftingManager.SetRecipe().

I am going to assume that it first checks to make sure that CraftingManager.CurrentRecipeId != synthesize.RecipeId. I am also going to assume that for some reason, some times, CurrentRecipeId does not actually equal the recipeId we are expecting, but whatever our last recipeId was. And my last assumption is that if we set the recipe and it has to switch pages in the UI, that this isn't always completed in the game by the time the method returns to us in RB and we move on to our StartCrafting method. StartCrafting will make it's call to SetRecipe because the CurrentRecipeId is not equal to the recipe we set out to craft because the window still hasn't finished switching to the newly set recipe.

2 possible solutions here that I can see.

1. If we want to set the recipe ourselves before we use StartCrafting, we should then await Coroutine.Wait(10000, () => CraftingManager.CurrentRecipeId == recipeIdThatWeSet); 10000 is overkill but it should never take this long anyway.
2. Fix any code issues that might be in StartCrafting (I did get this to throw the error once out of 100 attempts by setting the recipe to a different page) that would also cause this error due to the window switching too slowly and then just use that method.

Sorry if I am not clear on anything, it is quite late.

 

This definitely sounds promising. And I believe checking the current recipe after crafting or changing between level ranges or jobs is not always instantly available. Thanks for looking into this. Any chance of letting us set the HQ mats? I know it is more complicated than the other pieces, but I think it would make sense for it to be available for the developers to make use of.

 

Thank you very much for looking into it. If there's anything we can help with let us know.