Bug - Waiting for Info desertExploration Updated Twice in One Fight

[Alium]

Script I was running (loopgyou) crashed because it failed to open the pyramid even though desertExploration was 100. When looking in game exploration was really 98. Seems to be due to property being updated twice in a single combat. First update looks suspect to me as normally it is updated after all the After Battle things. Unfortunately don't have DEBUG log and don't know how to reproduce.

Have enabled debugging in my script wrapper so if happens again will upload. I had compass and camel equipped so incrementing by 3 is correct.

[255] The Arid, Extra-Dry Desert
Preference lastEncounter changed from giant giant giant centipede to rock scorpion
Encounter: rock scorpion
Preference crystalBallPredictions changed from 254:The Arid, Extra-Dry Desert:rock scorpion to
Round 0: Alium wins initiative!
Preference crystalBallPredictions changed from  to 254:The Arid, Extra-Dry Desert:cactuary
Round 1: You look in the mini crystal ball -- it looks like there's a cactuary prowling around nearby.
Round 1: Alium executes a macro!
Round 1: Alium uses the rock band flyers!
Round 2: You lose 19 hit points
Preference flyeredML changed from 4655 to 4834
Round 2: Alium casts INFINITE LOOP!
Round 3: rock scorpion takes 246 damage.
Round 3: Alium wins the fight!
After Battle: You watch the little you inside the mini crystal ball for a bit. They seem unusually competent. (+5 Stats)
After Battle: Fruderick kicks you in the ankle, in just the right place to be very effective chiropracty. If that's a word.
After Battle: You gain 11 hit points

Update #1
Preference desertExploration changed from 77 to 80
After Battle: You gain 6 Mana Points
You gain 668 Meat
Preference camelSpit changed from 50 to 53
After Battle: You hear a loud schlurrrrrk! You hear a loud schlurrrrrk! noise, and turn to see Fruderick sucking the liquid out of a bottle of malt liquor he found somewhere. (53% full)
After Battle: Your bulk increases as your nanites absorb the remains.
After Battle: You gain 1 Muscle
After Battle: You follow Fruderick further into the desert, since he seems to have a much better idea of where he's going than you do.
Preference lastCopyableMonster changed from giant giant giant centipede to rock scorpion
Preference _boomBoxFights changed from 8 to 9

Update #2
Preference desertExploration changed from 80 to 83
Preference crystalBallPredictions changed from 254:The Arid, Extra-Dry Desert:cactuary to 255:The Arid, Extra-Dry Desert:cactuary

 

[zarqon]

In the off chance that I am able to insert a related bird in the trajectory of the stone thrown to fix this bug, I'll also mention here that my desert tracking was off recently too with both the compass and the survival knife equipped. The page text said +4% explored after each fight but the property was only advancing by 2 or 3. If this is too unrelated to piggyback on this bug report, I'll grab the page text next time and report it properly as a separate bird, to be killed with its own unique stone.

 

[Veracity]

I don’t believe we have any support for the survival knife yet. Grab a DEBUG log, please.

 

[Veracity]

I decided to give Quantum Terrarium a go, so I ascended yesterday. Today I got a survival knife - and a Melodramedary - after I had unlocked the desert and bought a UV compass. Getting +5 desert exploration per turn was nice for a while. Freed the king with 10 turns left today. Not sure I've ever done a 2-day HC run before. Out of Standard, KoL autopulls all of your IOTMs.

I got logs, and coded up a fix.

r26517

 

[Veracity]

Lengthy and technical analysis of how FightRequest processes the response to a fight.php request.

processResults is called for the response to a fight.php request.
The response text can contain a single round - if the fight had a single action - or multiple rounds - if it executed a macro.

processResults cleans up some things - like rune spoon word replacesments - and calls updateCombatData(urlString, encounter, responseText) to parse it.

updateCombatData saves the responseText in FightRequest.lastResponseText.
It does some initial checks and initializes all sorts of stuff if currentRound is 0 - i.e., this is the first response text we've received for this fight.
It then creates a matcher which can be used to extract exactly the text pertaining to a single round (if you submitted a macro) or the whole page (if you submitted a single action) and increments the currentRound. We are now (at least) in round 1.

It is now time for processNormalResults(responseText, macroMatcher) to process all the rounds in the responseText.
If there are multiple rounds - from a macro - they are separated by "hr" tags - horizontal lines.
Every time we encounter such, we call FightRequest.updateRoundData(macroMatcher) to finish up the processing for the current round, and then move to the next round.
Finally, if we run out of rounds - no more "hr" tags - we call FightRequest.updateRoundData(macroMatcher) to finish up processing for the last round in the response.

updateRoundData will detect that this is the final round in the response and will detect if you won the battle.
If you won, the fight is over. If not, you might have lost or runaway, or you might be still in the fight.
If this was the final round in the response text and you are not still in battle, it calls updateFinalRoundData(responseText, won).

If you lost the fight, updateFinalRound calls QuestManager.updateQuestFightLost(responseText, monsterName)
If you won the fight, updateFinalRound calls QuestManager.updateQuestData(FightRequest.lastResponseText, monsterName)

That second one is where it calculates desert exploration. This is the only place in KoLmafia that method is called.

We expect that to be called after it has done all the regular processing for the last round - i.e., all that logging you get that says "After Battle:". That is why the Desert Exploration updating happens at the very end of the processing.

The puzzle is how it could happen in the middle of that processing.

After Battle: You gain 11 hit points
Preference desertExploration changed from 77 to 80
After Battle: You gain 6 Mana Points

As I said, if we encounter a "hr" tag, we know that that separates macro actions and we will finish the round processing - and if this is the final round (i.e. there is no further "macroaction") we'll do final round processing. Could there have been an "hr" tag right there between the HP gain and the MP gain? If so, we'd look for the next macroaction - and presumably not find it, since we knew we were in the final round. And if we did not find it, we'd log "unspecified macro action?". You did not get that.

But that seems the only way it could do "final round" processing twice: once when it saw a "hr" tag in the middle of final round processing and once after the whole text has been processed.

I'd really like to see the DEBUG log for that fight. Until/unless you can get this to happen again - with DEBUG logging - I've done as much analysis of this issue as I can.

 

[Alium]

Thanks for the detailed look! As promised, I have had DEBUG enabled every gloop since reporting this. Just hasn't happened again. Will update if/when it does.