Bug - Fixed Getting stuck in Spelunky limit mode

Verdant Purple

New member
This has occurred as recently as today in r28757 (with Java 21.0.9), but has affected multiple other versions over the past month or so, as well.

1. Use a Tales of Spelunking.
2. Play through Spelunky as normal.
3. Close the book in the last choice, and remain stuck in the Spelunky limit mode.
4. Be (mostly) unable do anything at all until completely exiting and restarting mafia.

Attempting to relog/timein without closing mafia just gets stuck in a refresh loop:
[CLI output]
Preference _concoctionDatabaseRefreshes changed from 619 to 620
Retrieving character data...
Updating inventory...
Preference _concoctionDatabaseRefreshes changed from 620 to 621
Retrieving familiar data...
Familiar data retrieved.
Preference _concoctionDatabaseRefreshes changed from 621 to 622
Retrieving character data...
Updating inventory...
... <repeating until restart>

There's typically no debug log, although it has produced this a few times which I suspected to be related to ChIT, but still get stuck without it installed:
[debug.txt]
(charpane.ash, line 5078)
class java.lang.StackOverflowError: null
java.lang.StackOverflowError
at net.sourceforge.kolmafia.request.GenericRequest.sendRequest(GenericRequest.java:1617)
at net.sourceforge.kolmafia.request.GenericRequest.externalExecute(GenericRequest.java:1415)
at net.sourceforge.kolmafia.request.GenericRequest.execute(GenericRequest.java:1403)
at net.sourceforge.kolmafia.request.GenericRequest.run(GenericRequest.java:1169)
at net.sourceforge.kolmafia.request.ApiRequest.updateStatusFromCharpane(ApiRequest.java:96)
at net.sourceforge.kolmafia.request.ApiRequest.updateStatus(ApiRequest.java:81)
at net.sourceforge.kolmafia.request.ApiRequest.updateStatus(ApiRequest.java:62)
at net.sourceforge.kolmafia.KoLmafia.resetAfterLimitmode(KoLmafia.java:1071)
at net.sourceforge.kolmafia.KoLCharacter.setLimitMode(KoLCharacter.java:1281)
at net.sourceforge.kolmafia.request.CharPaneRequest.processResults(CharPaneRequest.java:168)
at net.sourceforge.kolmafia.request.GenericRequest.processResponse(GenericRequest.java:2201)
at net.sourceforge.kolmafia.request.GenericRequest.retrieveServerReply(GenericRequest.java:2158)
at net.sourceforge.kolmafia.request.GenericRequest.retrieveServerReply(GenericRequest.java:1750)
at net.sourceforge.kolmafia.request.GenericRequest.externalExecute(GenericRequest.java:1416)
... <hundreds of lines of this repeating>
(charpane.ash, line 5078)

On one occasion I was able to manually use another Tales of Spelunking via chat command while stuck in Spelunky mode. This reverted me back to normal mode after entering the Spelunky zone, and I similarly couldn't do anything until a full restart.

On another occasion I was able to manually equip an outfit and perform one adventure in a normal zone, also via chat commands. Mafia freaked out a bit during, but the fight completed more or less normally, before ultimately getting stuck in a refresh loop afterwards:
[session.txt]
...
custom outfit -2826
<my outfit is not called "-2826">
...
adventure.php?snarfblat=384
Preference lastEncounter changed from <a class=nounder href="campground.php">your campsite</a>. to lynyrd skinner
Encounter: lynyrd skinner
Round 0: Verdant Purple wins initiative!
Adjusted combat item count: 4:20 bomb
<hundreds of lines adjusting every combat item>
...
Preference _concoctionDatabaseRefreshes changed from 512 to 513
Preference lastAdventureTrail changed from Dreadsylvanian Castle to A Mob of Zeppelin Protesters
Preference _concoctionDatabaseRefreshes changed from 513 to 514
Preference _concoctionDatabaseRefreshes changed from 514 to 515
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Preference _concoctionDatabaseRefreshes changed from 515 to 516
Preference _concoctionDatabaseRefreshes changed from 516 to 517
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Preference _concoctionDatabaseRefreshes changed from 517 to 518
Preference lastAdventureTrail changed from A Mob of Zeppelin Protesters to The Jungle
Preference _concoctionDatabaseRefreshes changed from 518 to 519
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Encounter: lynyrd skinner
Round 0: Verdant Purple attacks!
Preference _lastCombatActions changed from to attack;
Encounter: lynyrd skinner
<this was only one encounter>
...
Preference lastAdventure changed from The Jungle to A Mob of Zeppelin Protesters
*** slot hat: KoL has eldritch hat but KoLmafia has (none)
*** slot weapon: KoL has cursed pirate cutlass but KoLmafia has (none)
*** slot off-hand: KoL has can of mixed everything but KoLmafia has (none)
*** slot back: KoL has McHugeLarge duffel bag but KoLmafia has (none)
*** slot shirt: KoL has Stephen's lab coat but KoLmafia has (none)
*** slot pants: KoL has eldritch pants but KoLmafia has (none)
*** slot acc1: KoL has Mr. Cheeng's spectacles but KoLmafia has (none)
*** slot acc2: KoL has mafia thumb ring but KoLmafia has (none)
*** slot acc3: KoL has lucky gold ring but KoLmafia has (none)
Preference _concoctionDatabaseRefreshes changed from 521 to 522
Preference _concoctionDatabaseRefreshes changed from 522 to 523
Preference _concoctionDatabaseRefreshes changed from 523 to 524
Preference _concoctionDatabaseRefreshes changed from 524 to 525
Preference _concoctionDatabaseRefreshes changed from 525 to 526
Preference _concoctionDatabaseRefreshes changed from 526 to 527
<stuck refreshing until a restart>
...
 
So the code around the crash is the following in CharPaneRequest:
Code:
// Are we in a limitmode?
if (responseText.contains(">Last Spelunk</a>")) {
  KoLCharacter.setLimitMode(LimitMode.SPELUNKY);
  SpelunkyRequest.parseCharpane(responseText);
  return true;
}

if (responseText.contains("You're Batfellow")) {
  KoLCharacter.setLimitMode(LimitMode.BATMAN);
  BatManager.parseCharpane(responseText);
  return true;
}

if (KoLCharacter.getLimitMode() == LimitMode.SPELUNKY) {
  KoLCharacter.setLimitMode(LimitMode.NONE);
}

So when we try to leave spelunky mode after exiting spelunky, we set the limit mode to none, and as part of that we update the status, and as part of that we get various status items from the charpane, which involves refreshing the charpane and repeating this in a loop because when we hit the "set limit mode to none" method, we do this switch status thing before actually updating the limit mode in memory.

Not sure how this ever doesn't have a problem. Probably a race condition of some sort.
 
Well, I'm glad I'm not alone in the "how does this even work?" camp. It definitely didn't happen at first, although I'm not sure when exactly it started. I figured it was just a weird one-off glitch, but it's been consistently sticking every time since then. I did ask a few others I've seen on the leaderboard, but they either ignored me or didn't use mafia, so I'm not really sure if this affects anyone else, tbh.

I had tried just manually resetting the limitMode after the final Spelunky choice, which partially worked. It at least removed all the Spelunky-specific stuff, but still left my normal inventory and everything empty.

Code:
case 1027 -> { // The End of the Tale of Spelunking
    if (ChoiceManager.lastDecision == 1) {
      // Remove all virtual items from inventory/tally
      SpelunkyRequest.resetItems();
      KoLCharacter.setLimitMode(LimitMode.NONE);
    }
  }

I'm not sure how I missed the resetAfterLimitMode() method. This is only directly called when picking a perk, which notably stops happening after you get all the perks, so I can only assume that's when it started getting stuck, for me at least. That does roughly fit the timeline as I recall.

Code:
    case 1042 -> // Pick a Perk
      KoLmafia.resetAfterLimitmode();

I just tried calling that after resetting the limitMode upfront (in postChoice1), as well as in a new postChoice2 for the End of the Tale with all the perks already picked, but that just freezes mid-choice without even making it to the final leaderboard page. Not sure what I'm missing here, and it looks like that reset method should get called as part of clearing the limitMode anyway, so it doesn't seem like that should be necessary in the first place either.
 
This isn't quite fixed, but is definitely an improvement. It does exit the limitMode correctly now, but at least sometimes fails to refresh inventory/skills/etc, although a manual refresh does resolve that without a full restart.

I assume this is why resetAfterLimitmode was being called directly to begin with, despite the limitMode being cleared elsewhere, and the limitMode setter attempting to call reset itself during that process:
Code:
// If it does require making requests, can't do it in a fight or choice
if (KoLCharacter.limitMode.requiresReset()
    && !GenericRequest.abortIfInFightOrChoice(true)) {
  KoLmafia.resetAfterLimitmode();
}

Maybe the results page that follows the final choice counts as a fight/choice in some capacity and cancels that? I can dig into this a bit more tomorrow, but I imagine just calling reset again(?) should take care of it.
 
If you type "debug on" on the CLI, you'll get a debug log of every network request made and what the resulting pages were.

Looking at postChoice2, it should set handlingChoice to the needed before calling your specific postChoice2 method:
Code:
ChoiceManager.handlingChoice = ChoiceManager.stillInChoice(text);

if (urlString.startsWith("choice.php") && text.contains("charpane.php")) {
  // Since a charpane refresh was requested, a turn might have been spent
  AdventureSpentDatabase.setNoncombatEncountered(true);
}

if (ChoiceManager.lastChoice == 0 || ChoiceManager.lastDecision == 0) {
  // This was a visit
  return;
}

ChoiceControl.postChoice2(urlString, request);
unless after finishing you're tripping the stillInChoice handler.
 
Two more runs down, with debug on from just after the last turn > Exit > Close the Book > Back to the Main Map.

The first with stock release r28761 behaved as before, exiting the limitMode correctly but failing to actually update any skills/equipment/etc., resolvable with a soft refresh. In the logs it looks like it did attempt to reset everything, not blocked by the choice handler, but just didn't save the results for some reason.

The second was modified to call resetAfterLimitmode again after clearing the limitMode and behaved as I would expect, resetting everything properly as far as I could tell. The debug logs were largely the same as earlier, but showed the reset-related requests all being made a second time, the only exception being `api.php?what=status&for=KoLmafia`, which is not called in the first batch:

Requesting: https://www.kingdomofloathing.com/place.php?whichplace=spelunky&action=spelunky_quit
Requesting: https://www.kingdomofloathing.com/choice.php?forceoption=0
Requesting: https://www.kingdomofloathing.com/choice.php?pwd&whichchoice=1027&option=1
Requesting: https://www.kingdomofloathing.com/charpane.php

Requesting: https://www.kingdomofloathing.com/charsheet.php
Requesting: https://www.kingdomofloathing.com/api.php?what=inventory&for=KoLmafia
Requesting: https://www.kingdomofloathing.com/account_manageoutfits.php
Requesting: https://www.kingdomofloathing.com/familiar.php
Requesting: https://www.kingdomofloathing.com/campground.php?action=inspectdwelling
Requesting: https://www.kingdomofloathing.com/campground.php?action=inspectkitchen
Requesting: https://www.kingdomofloathing.com/campground.php?action=workshed
Requesting: https://www.kingdomofloathing.com/campground.php?action=bookshelf

Requesting: https://www.kingdomofloathing.com/api.php?what=status&for=KoLmafia
Requesting: https://www.kingdomofloathing.com/charsheet.php
Requesting: https://www.kingdomofloathing.com/api.php?what=inventory&for=KoLmafia
Requesting: https://www.kingdomofloathing.com/account_manageoutfits.php
Requesting: https://www.kingdomofloathing.com/familiar.php
Requesting: https://www.kingdomofloathing.com/campground.php?action=inspectdwelling
Requesting: https://www.kingdomofloathing.com/campground.php?action=inspectkitchen
Requesting: https://www.kingdomofloathing.com/campground.php?action=workshed
Requesting: https://www.kingdomofloathing.com/campground.php?action=bookshelf

Requesting: https://www.kingdomofloathing.com/charpane.php
Requesting: https://www.kingdomofloathing.com/chit_custom.css
Requesting: https://www.kingdomofloathing.com/main.php

setLimitMode tries to call resetAfterLimitmode before actually changing the limitMode, and ApiRequest.updateStatus just doesn't call the status API in some cases, so even though we're trying to exit Spelunky mode it still relies on the charPane for a status update at this point:
Code:
# KoLCharacter.setLimitMode
        if (KoLCharacter.limitMode.requiresReset()
            && !GenericRequest.abortIfInFightOrChoice(true)) {
          KoLmafia.resetAfterLimitmode();
        }
      }
      case BATMAN -> BatManager.setCombatSkills();
    }
    KoLCharacter.limitMode = limitmode;
  }

# ApiRequest.updateStatus
    if (KoLCharacter.getLimitMode().requiresCharPane()
        || KoLCharacter.inNoobcore()
        || KoLCharacter.inPokefam()
        || KoLCharacter.inDisguise()) {
      return ApiRequest.updateStatusFromCharpane();
    }

# LimitMode
  public boolean requiresCharPane() {
    return switch (this) {
      case SPELUNKY, BATMAN -> true;
      default -> false;
    };
  }

I haven't tried Batfellow (and can't exactly afford to), but does that exhibit the same fail-to-refresh behavior? It doesn't handle exiting its limitMode in the roundabout way Spelunky was set up to before, via CharPaneRequest, but also doesn't explicitly resetAfterLimitMode during the final choice, so I suspect it would not update one's status properly at the end, either.

Then again, I'm a bit unclear on why a status update is required to refresh all the other things, anyway, or if something else is going on to prevent those results being saved. At the very least, I showed no available skills or inventory after the first run, despite getting appropriate responses from both `charsheet.php` and `api.php?what=inventory&for=KoLmafia`, though I didn't check the rest.
 
In your debug logs, when it loads the charpane, does ">Last Spelunk</a>" appear? That is, is it setting it back to Spelunky mode after setting it to None?
 
Nope, no ">Last Spelunk</a>" after the quit action. It didn't appear to have returned to Spelunky mode, either. The charpane did switch back to the normal version in both the relay browser and the GUI, and the equipment manager had all three accessory slots available.

All the equipment dropdowns were just empty, as well as the general inventory, the skill casting menu, and possibly outfits (unsure on that). I did appear to have my current/previous familiar still selected in the charpane, but didn't check if I had others available to switch to, and I feel like the familiar dropdown below the equipment may have actually been blank itself (also unsure). I didn't look at anything in the campground. In run 2 with the double requests, all of this appeared to be populated correctly.
 
I think the cleanest solution is just to move resetAfterLimitMode to be called after resetting the limit mode (if required). We don't need to be relying on limit mode-specific status updates while trying to exit that mode, so this avoids skipping the status API or duplicating the other requests.

Still not sure why that status update is required for all the other reset APIs to be handled, or if something else is going on there, but unless this breaks Batfellow in some way, this should resolve the issue.

PR: https://github.com/kolmafia/kolmafia/pull/3174
 
Back
Top