Strange A.I. behavior that is leading to illegal plays

[TheLastNarwhal]

Describe the bug
Lately, in the snapshots from at least 12.22 and onwards the A.I. is paying/casting spells/activating abilities strangely. It will tap a bunch of mana for seemingly no reason, no spells cast, no abilities activated, but then when priority is passed the spell will be cast/ability activated.

I didn't fully understand that that was what was happening until right now. I just assumed it was attempting to casting spells and then failing to cast, like it does sometimes. I caught it red handed this time though, 'cause it tapped all its mana in postcombat main and then moved to end phase and then the spell it "cast" and ability it "activated" appeared on the stack.

To Reproduce
Steps to reproduce the behavior:
I have no idea how you would be able to replicate this behavior other than to play a lot of games and catch it happening...

Expected behavior
For this to not happen?

Screenshots

See how it tapped all the mana during postcombat main then moved to end step and cast the spell. I should also point out that it activated Brittle Effigy during postcombat main too, but the ability didn't hit the stack until end step.

Desktop (please complete the following information):

• OS: Kubuntu 22.04 (just in case OS matters with this issue)
• Forge Version: forge-installer-2.0.01-SNAPSHOT-01.01

[tool4ever]

Please try to produce a gamestate file before it happens
(if you give me one after maybe it's good enough)

[TheLastNarwhal]

I don't think it will be possible to get a gamestate before it happens. It's impossible to predict and it's not something that happens all the time. I can definitely try to produce a gamestate file while it's happening though, like if I notice mana being paid but no spells cast.

[TheLastNarwhal]

@tool4ever

I actually thought it would be harder to catch this than it was, only took 4 or so games before it happened again. Unfortunately it's not possible to record the gamestate before it happens, but I did save the state right after the A.I. paid a bunch of mana for no apparent reason, then during the end phase the spell appeared on the stack.

state.txt

[TheLastNarwhal]

Happened again in the very next game.

state 2.txt

Sidenote
This started happening some time ago and I never really bothered to report it, but since it's in the game here I may as well. Draft only cards are being included in the random commander decks and they shouldn't be, or at least I don't think they should be, 'cause aren't they illegal?

[TheLastNarwhal]

Interesting... It happened a second time during the above game and then when I tried to save the gamestate this error occurred.

The error:

Casting the spell on end step:

[tool4ever]

Trying to manually edit the states back to Main1 showed no anomaly.

With all the mana generated it does look like there might be another SA involved which would be good to know.

There really should be hints in your Forge.log, especially for the Java error.

A rough overview of commits from your given timeframe doesn't give me a solid lead. If possible narrow it more e.g. starting with final last year release...

[TheLastNarwhal]

This is the Forge.log for the Java error.

java.lang.IndexOutOfBoundsException: Index -1 out of bounds for length 3 at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64) at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70) at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:266) at java.base/java.util.Objects.checkIndex(Objects.java:361) at java.base/java.util.ArrayList.get(ArrayList.java:427) at forge.ai.GameState.initFromGame(GameState.java:229) at forge.player.PlayerControllerHuman$DevModeCheats.dumpGameState(PlayerControllerHuman.java:2494) at forge.screens.match.controllers.CDev.dumpGameState(CDev.java:98) at forge.screens.match.controllers.CDev$1.mousePressed(CDev.java:74) at java.desktop/java.awt.AWTEventMulticaster.mousePressed(AWTEventMulticaster.java:288) at java.desktop/java.awt.Component.processMouseEvent(Component.java:6623) at java.desktop/javax.swing.JComponent.processMouseEvent(JComponent.java:3389) at java.desktop/java.awt.Component.processEvent(Component.java:6391) at java.desktop/java.awt.Container.processEvent(Container.java:2266) at java.desktop/java.awt.Component.dispatchEventImpl(Component.java:5001) at java.desktop/java.awt.Container.dispatchEventImpl(Container.java:2324) at java.desktop/java.awt.Component.dispatchEvent(Component.java:4833) at java.desktop/java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4948) at java.desktop/java.awt.LightweightDispatcher.processMouseEvent(Container.java:4572) at java.desktop/java.awt.LightweightDispatcher.dispatchEvent(Container.java:4516) at java.desktop/java.awt.Container.dispatchEventImpl(Container.java:2310) at java.desktop/java.awt.Window.dispatchEventImpl(Window.java:2780) at java.desktop/java.awt.Component.dispatchEvent(Component.java:4833) at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:775) at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:720) at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:714) at java.base/java.security.AccessController.doPrivileged(AccessController.java:399) at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:86) at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:97) at java.desktop/java.awt.EventQueue$5.run(EventQueue.java:747) at java.desktop/java.awt.EventQueue$5.run(EventQueue.java:745) at java.base/java.security.AccessController.doPrivileged(AccessController.java:399) at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:86) at java.desktop/java.awt.EventQueue.dispatchEvent(EventQueue.java:744) at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:203) at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:124) at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:113) at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:109) at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101) at java.desktop/java.awt.EventDispatchThread.run(EventDispatchThread.java:90)

Here's the full log and I believe I played a total of two games. It's kinda filled with failed fetches for a blood token though.

forge.log

[tool4ever]

Alright, like I suspected there are some problems with mana payment which seem to be related to cost raising. Possibly a regression that has lead to an increase of this outcome.
The crash is kind of unrelated and happens because some players are already out of the game.

[tool4ever]

• I've confirmed SpellAbilityAi: move willPayUnlessCost to EffectSpecific Code #6652 as cause
• and applied a fix that should restore correct behaviour