I just did a shore trip through the relay browser with debug logging on. Here's some info I extracted from the log:
Code:
GET /adventure.php?snarfblat=355 HTTP/1.1
Requesting: http://www.kingdomofloathing.com/adventure.php?snarfblat=355
Retrieved: http://www.kingdomofloathing.com/adventure.php?snarfblat=355
HTTP/1.1 302 Found
Location: choice.php?forceoption=0
GET /choice.php?forceoption=0 HTTP/1.1
Requesting: http://www.kingdomofloathing.com/choice.php?forceoption=0
Retrieved: http://www.kingdomofloathing.com/choice.php?forceoption=0
HTTP/1.1 200 OK
POST /choice.php HTTP/1.1
Requesting: http://www.kingdomofloathing.com/choice.php?pwd&whichchoice=793&option=2
Retrieved: http://www.kingdomofloathing.com/choice.php?pwd&whichchoice=793&option=2
You lose 3 Adventures
Processing result: Advs Used: -3
HTTP/1.1 200 OK
GET /charpane.php HTTP/1.1
Requesting: http://www.kingdomofloathing.com/charpane.php
GET /charpane.php HTTP/1.1
Requesting: http://www.kingdomofloathing.com/charpane.php
Retrieved: http://www.kingdomofloathing.com/charpane.php
Field: Date = [Mon, 30 Jun 2014 19:25:02 GMT]
var turnsthisrun = 458136
HTTP/1.1 200 OK
Retrieved: http://www.kingdomofloathing.com/charpane.php
Field: Date = [Mon, 30 Jun 2014 19:25:02 GMT]
var turnsthisrun = 458136
HTTP/1.1 200 OK
The timestamps and "turnsthisrun" are used by CharPaneRequest to decide if this charpane is out of order.
For some reason, the browser is asking for the charpane twice. KoLmafia dutifully passes on those requests and processes both responses.
Note that we get the result of the shore trip and process the "You lose 3 adventures" from it - which updates KoLmafia's idea of turns spent this run - and then we process two charpanes, neither of which is rejected. What do we do with the adventures we parse from the charpane?
Code:
ResultProcessor.processAdventuresUsed( turnsThisRun - mafiaTurnsThisRun );
Since turnsThisRun == mafiaTurnsThisRun, this will do nothing.
Similarly, if you automate, when the response to the vacation comes back, we call api.php and do this:
Code:
int turnsThisRun = JSON.getInt( "turnsthisrun" );
...
int mafiaTurnsThisRun = KoLCharacter.getCurrentRun();
ResultProcessor.processAdventuresUsed( turnsThisRun - mafiaTurnsThisRun );
Now, if we received a charpane response after we submitted the choice to take the vacation but before we got the response which happened to already have the updated turn counter in it, we would deduct 3 adventures when we process the charpane and then deduct 3 more when we process the response to the vacation, which would be consistent with this report. But, why would we have an asynchronous request to fetch the charpane?
If we assume that the user didn't bang on the "refresh" button on the GUI (which submits an api.php request), the only thing I can guess is something coming from chat. So, lets's see if I can force something like that:
Code:
GET /newchatmessages.php?lasttime=0000000102&afk=0 HTTP/1.1
Requesting: http://www.kingdomofloathing.com/newchatmessages.php?lasttime=1380310296&pwd
Retrieved: http://www.kingdomofloathing.com/newchatmessages.php?lasttime=1380310296&pwd
<font color=green><a class=nounder target=mainpane href=showplayer.php?who=121572><b>Veracity</b></a> has fortified you with the Empathy of the Newt. (15 Adventures)</font><br><!--lastseen:1380310304-->
Requesting: http://www.kingdomofloathing.com/api.php?what=status&for=KoLmafia
Retrieved: http://www.kingdomofloathing.com/api.php?what=status&for=KoLmafia
HTTP/1.1 200 OK
Yes, indeed. My multi was logged into KoLmafia with debug logging. I logged directly in to a browser and buffed her. We got the chat message and requested api.php. That happens in ChatManager.processEvent. It will do that any time it gets what it thinks is an "event" (something it will display in green) which has the word " has " in it.
We have had similar issues with parsing Meat, I think, if we deduct Meat from a response and also from the charpane.
I'll have to think about this.
