Bug - Fixed CLI print bugged when consuming multiples of the same item.

Ensiferum

Member
Mafia only displays the adventure and stat yields from the last of the consumed items. At first I thought this is related to consuming right after placing the McGuffin in an Ed run without refreshing the session, but apparently the same happens to a perma-aftercore account.


The CLI prints of the 2 accounts:
Code:
Eating 2 hot hi mein...
You acquire an effect: Hot Breath (5)
You lose some of an effect: Got Milk (-5)
You gain 38 Adventures
You gain 73 Fortitude
You gain 22 Enchantedness
You gain 32 Cheek
You gain a Moxie point!
You lose some of an effect: Got Milk
Finished eating 2 hot hi mein.

Code:
Eating 3 hot hi mein...
You acquire an effect: Hot Breath (5)
You lose some of an effect: Got Milk (-5)
You lose some of an effect: Got Milk (-5)
You gain 30 Adventures
You gain 73 Muscleboundness
You gain 16 Mysteriousness
You gain 36 Roguishness
You lose some of an effect: Got Milk
Finished eating 3 hot hi mein.
 

Attachments

  • DEBUG_20150311_consumption.txt
    8.9 KB · Views: 45
  • DEBUG_20150311_aftercoreconsumption.txt
    10.7 KB · Views: 31

Veracity

Developer
Staff member
Doesn't happen to me.

> eat 5 super salad

Eating 5 super salad...
You gain 19 Adventures
You gain 32 Fortitude
You gain 37 Magicalness
You gain 36 Cheek
You lose some of an effect: Got Milk
You gain 19 Adventures
You gain 40 Strengthliness
You gain 32 Magicalness
You gain 38 Roguishness
You lose some of an effect: Got Milk
You gain 19 Adventures
You gain 37 Beefiness
You gain 34 Magicalness
You gain a Mysticality point!
You gain 37 Roguishness
You lose some of an effect: Got Milk
You gain 19 Adventures
You gain 30 Strongness
You gain 34 Magicalness
You gain 35 Cheek
You lose some of an effect: Got Milk
You gain 17 Adventures
You gain 31 Muscleboundness
You gain 33 Magicalness
You gain 32 Cheek
You lose some of an effect: Got Milk
Finished eating 5 super salad.
and

> drink 4 divine

Drinking 4 Divine...
You gain 18 Adventures
You gain 18 Fortitude
You gain 25 Wizardliness
You gain 4 Drunkenness
You lose some of an effect: Ode to Booze
You gain 21 Adventures
You gain 16 Strengthliness
You gain 26 Wizardliness
You gain 4 Drunkenness
You lose some of an effect: Ode to Booze
You gain 21 Adventures
You gain 16 Strongness
You gain 25 Enchantedness
You gain 4 Drunkenness
You lose some of an effect: Ode to Booze
You gain 21 Adventures
You gain 18 Fortitude
You gain 25 Enchantedness
You gain 4 Drunkenness
You lose some of an effect: Ode to Booze
Finished drinking 4 Divine.
 

Ensiferum

Member
It's a bit hard to track when exactly does it happen. Seems some food items are affected, some aren't.

I tried on another character and it ate 4x insanely spicy bean burritos with normal CLI prints, then the last 3 fullnes was 3x bucket of honey, where the buggy behaviour presented itself agan, printing "You lose some of an effect: Got Milk (-50)" 3 times. I did not have 150 turns of got milk for sure, nor can it be lost while filling 3 stomach.

Lost is correct that I do not have an in-game fullness counter on any of the accounts.
 

Veracity

Developer
Staff member
I tried on another character and it ate 4x insanely spicy bean burritos with normal CLI prints, then the last 3 fullnes was 3x bucket of honey, where the buggy behaviour presented itself again
It's sounding more and more like the "buggy behavior" is in KoL itself.

Get a DEBUG log next time and lets see what KoL said when KoLmafia seemingly did not report all of the consumption messages. Thanks.

printing "You lose some of an effect: Got Milk (-50)" 3 times. I did not have 150 turns of got milk for sure, nor can it be lost while filling 3 stomach.
KoLmafia prints exactly what KoL prints when "You lose some of an effect"; it does not edit or change the message in any way. I wonder why KoL decided to put the (-50) in those messages?

Lost is correct that I do not have an in-game fullness counter on any of the accounts.
Neither do I.
 

Darzil

Developer
I suspect it's related to my attempts to parse effects based on descId rather than name somehow.

At somepoint we might want to completely revise that section of FightRequest and ResultProcessor, as having to pre-parse Items and Effects then strip out the data they needed and parse the rest isn't ideal.
 

Veracity

Developer
Staff member
Here is a DEBUG log. I ate 6 super salads:

Code:
Requesting: http://www.kingdomofloathing.com/inv_eat.php?whichitem=2027&ajax=1&quantity=6
Retrieved: http://www.kingdomofloathing.com/inv_eat.php?whichitem=2027&ajax=1&quantity=6
and here is the response text.

Code:
<script type="text/javascript">top.charpane.location.href="charpane.php";</script><script type="text/javascript">if (window.updateInv) updateInv({"2027":0})</script><script type="text/javascript">if (!window.updateInv && parent.mainpane.updateInv) parent.mainpane.updateInv({"2027":0})</script><center><table  width=95%  cellspacing=0 cellpadding=0><tr><td style="color: white;" align=center bgcolor=blue><b>Results:</b></td></tr><tr><td style="padding: 5px; border: 1px solid blue;"><center><table><tr><td><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 17 Adventures.</td></tr></table></center><center><table><tr><td>You gain 38 Beefiness.</td></tr></table></center><center><table><tr><td>You gain 44 Enchantedness.</td></tr></table></center><center><Table><tr><td>You gain 33 Chutzpah.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center><p><center><b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 16 Adventures.</td></tr></table></center><center><table><tr><td>You gain 35 Muscleboundness.</td></tr></table></center><center><table><tr><td>You gain 38 Enchantedness.</td></tr></table></center><center><Table><tr><td>You gain 35 Roguishness.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center><p><center><b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 19 Adventures.</td></tr></table></center><center><table><tr><td>You gain 31 Strengthliness.</td></tr></table></center><center><table><tr><td>You gain 35 Mysteriousness.</td></tr></table></center><center><Table><tr><td>You gain 37 Cheek.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center><p><center><b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 16 Adventures.</td></tr></table></center><center><table><tr><td>You gain 36 Fortitude.</td></tr></table></center><center><table><tr><td>You gain 38 Wizardliness.</td></tr></table></center><center><Table><tr><td>You gain 36 Smarm.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center><p><center><b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 17 Adventures.</td></tr></table></center><center><table><tr><td>You gain 31 Muscleboundness.</td></tr></table></center><center><table><tr><td>You gain 40 Wizardliness.</td></tr></table></center><center><Table><tr><td>You gain 37 Smarm.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center><p><center><b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 19 Adventures.</td></tr></table></center><center><table><tr><td>You gain 32 Beefiness.</td></tr></table></center><center><table><tr><td>You gain 40 Mysteriousness.</td></tr></table></center><center><Table><tr><td>You gain 38 Chutzpah.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center></td></tr></table></center></td></tr><tr><td height=4></td></tr></table></center>
Notice that KoL says this:

Code:
You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 17 Adventures.</td></tr></table></center><center><table><tr><td>You gain 38 Beefiness.</td></tr></table></center><center><table><tr><td>You gain 44 Enchantedness.</td></tr></table></center><center><Table><tr><td>You gain 33 Chutzpah.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center>
It listed the consumption effects for the first super salad.

It also said "You lose some of an effect: Got Milk (3 Adventures)".

That "(3 Adventures)" is a change, by the way; I recall being unhappy that we couldn't tell how much of the effect you lost, so we'd simply remove all of it and update it when we refreshed the charpane. With this KoL change, it looks like we can simply decrement it by the appropriate amount. Sweet!

This was followed by:

Code:
<b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/crimbowl2.gif" width=30 height=30><br></center><blockquote>You eat the super salad.  Unsurprisingly, it tastes super!<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 16 Adventures.</td></tr></table></center><center><table><tr><td>You gain 35 Muscleboundness.</td></tr></table></center><center><table><tr><td>You gain 38 Enchantedness.</td></tr></table></center><center><Table><tr><td>You gain 35 Roguishness.</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (3 Adventures)</td></tr></table></center>
and then... the next consumption.

Here is what my gCLI said:

Code:
Eating 6 super salad...
You gain 17 Adventures
You gain 38 Beefiness
You gain 44 Enchantedness
You gain 33 Chutzpah
You lose some of an effect: Got Milk
You gain 16 Adventures
You gain 35 Muscleboundness
You gain 38 Enchantedness
You gain 35 Roguishness
You lose some of an effect: Got Milk
You gain 19 Adventures
You gain 31 Strengthliness
You gain 35 Mysteriousness
You gain 37 Cheek
You lose some of an effect: Got Milk
You gain 16 Adventures
You gain 36 Fortitude
You gain 38 Wizardliness
You gain 36 Smarm
You lose some of an effect: Got Milk
You gain 17 Adventures
You gain 31 Muscleboundness
You gain 40 Wizardliness
You gain 37 Smarm
You lose some of an effect: Got Milk
You gain 19 Adventures
You gain 32 Beefiness
You gain 40 Mysteriousness
You gain 38 Chutzpah
You lose some of an effect: Got Milk
Finished eating 6 super salad.
We parse and print everything KoL says.

If you are not seeing that, then KoL is doing something different for you than it does for every one of my characters.

Post a DEBUG log, please. There is nothing more I can say about this until I see what KoL is telling YOUR characters.
 

Ensiferum

Member
Are the two debug logs in the first post not enough?
I doubt there is going to be anything different in further debug logs reproducing the same issue.

That "(X Adventures)" has been there for months and the errors in the parsing only started in the past few days.
 
Last edited:

Veracity

Developer
Staff member
Oh. Sorry. For some reason, I thought those were session logs or something. So, let's see:

Code:
Requesting: http://www.kingdomofloathing.com/inv_eat.php?whichitem=1592&ajax=1&quantity=2
Retrieved: http://www.kingdomofloathing.com/inv_eat.php?whichitem=1592&ajax=1&quantity=2
yields:

Code:
You eat the hot hi mein.  You're so hi-mein-tenance, man.<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 38 Adventures.</td></tr></table></center><center><table><tr><td>You gain 73 Fortitude.</td></tr></table></center><center><table><tr><td>You gain 22 Enchantedness.</td></tr></table></center><center><Table><tr><td>You gain 32 Cheek.<br><b>You gain a Moxie point!</b></td></tr></table></center><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/breath.gif" onClick='eff("7ecbd57bcb86d63be06bb6d4b8e7229f");' width=30 height=30 alt="Hot Breath" title="Hot Breath"></td><td valign=center class=effect>You acquire an effect: <b>Hot Breath</b><br>(duration: 5 Adventures)</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (5 Adventures)</td></tr></table></center>
The first item consumption and then:

Code:
<b>and then...</b></center></p><center><img src="http://images.kingdomofloathing.com/itemimages/bowl.gif" width=30 height=30><br></center><blockquote>You eat the hot hi mein.  You're so hi-mein-tenance, man.<center><table><tr><td><img src="http://images.kingdomofloathing.com/itemimages/hourglass.gif" height=30 width=30 alt="Adventures"></td><td valign=center>You gain 39 Adventures.</td></tr></table></center><center><table><tr><td>You gain 72 Muscleboundness.</td></tr></table></center><center><table><tr><td>You gain 22 Wizardliness.</td></tr></table></center><center><Table><tr><td>You gain 32 Cheek.</td></tr></table></center><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/breath.gif" onClick='eff("7ecbd57bcb86d63be06bb6d4b8e7229f");' width=30 height=30 alt="Hot Breath" title="Hot Breath"></td><td valign=center class=effect>You acquire an effect: <b>Hot Breath</b><br>(duration: 5 Adventures)</td></tr></table></center></blockquote><center><table><tr><td><img class=hand src="http://images.kingdomofloathing.com/itemimages/milk.gif" onClick='eff("225aa10e75476b0ad5fa576c89df3901");' width=30 height=30></td><td valign=center class=effect>You lose some of an effect: <b>Got Milk</b> (5 Adventures)</td></tr></table></center>
The second consumption. Looks the same as what happens for me.

Processing results...
You acquire an effect: Hot Breath (5)
Processing result: Hot Breath (5)
You lose some of an effect: Got Milk (-5)
Processing result: Got Milk (-5)
Parsing result: You gain 38 Adventures
You gain 38 Adventures
Processing result: Advs Used: 38
Parsing result: You gain 73 Fortitude
You gain 73 Fortitude
Processing result: Substats: 73 / 0 / 0
Parsing result: You gain 22 Enchantedness
You gain 22 Enchantedness
Processing result: Substats: 0 / 22 / 0
Parsing result: You gain 32 Cheek
You gain 32 Cheek
Processing result: Substats: 0 / 0 / 32
You gain a Moxie point!
You lose some of an effect: Got Milk
Processing result: hot hi mein (-2)

Well, that's exactly how it does not work for me.

OK. Let's parse your response text:

> test load hm.html

Read 3,152 bytes into a 3,152 character string

> test result

You acquire an effect: Hot Breath (5)
You lose some of an effect: Got Milk (-5)
You gain 38 Adventures
You gain 73 Fortitude
You gain 22 Enchantedness
You gain 32 Cheek
You gain a Moxie point!
You lose some of an effect: Got Milk
returned true
So I can reproduce it.
 

Veracity

Developer
Staff member
Yeah, OK. Darzil, you are right. This is due to your pre-processing effects. Two problems:

- You need to remove the entire HTML table that contains the effect, just as we do for items.
- You need to call processEffect(), not processItem() on the AdventureResult. :)

I'll have a fix soon.
 

Veracity

Developer
Staff member
I suspect it's related to my attempts to parse effects based on descId rather than name somehow.
Correct. Revision 15577 fixes it.

At some point we might want to completely revise that section of FightRequest and ResultProcessor, as having to pre-parse Items and Effects then strip out the data they needed and parse the rest isn't ideal.
Yes, I am not happy that all the "You gain an effect" and "You lose (some of) an effect" lines now appear at the top of the results, rather at the spot where they happen. I do like that we remove the appropriate amount of the effect that you lose "some of".

I guess we need two queues: items gained/lost and effects gained/lost. We can preprocess to register new items and effects, but then process the results and when we find an item or effect, pull off the first from the respective queue. Or something.

But yes - the current output is definitely not ideal.
 
Top