Bug Crash Using Script

bumcheekcity

bumcheekcity

Active member
v10815

Mafia was running slowly and failing to properly escape when I press ESCAPE and it gives me "World Peace".

I call the ascend script, which doesn't do anything. I give it 20 seconds, press ESCAPE. Mafia gives me "World Peace", I then type "mcd 2" (or basically any command), and it just starts queueing them.

Code: 
> cast soli

Casting Song of Solitude 1 times...
You lose an effect: Song of Accompaniment
You acquire an effect: Song of Solitude (duration: 40 Adventures)
Song of Solitude was successfully cast.

[257] Spooky Forest
Encounter: spooky vampire
Round 0: bumcheekcity wins initiative!
Round 1: bumcheekcity casts RETURN!

[257] Spooky Forest
Encounter: Arboreal Respite
Encounter: The Road Less Traveled
Encounter: Tree's Last Stand
Encounter: spooky sapling
You spent 100 Meat
You acquire an item: spooky sapling

> call scripts\dev\bumcheekascend\bumcheekascend.ash

KoLmafia declares world peace.

> CURRENT: call scripts\dev\bumcheekascend\bumcheekascend.ash
> QUEUED 1: mcd 2

> CURRENT: call scripts\dev\bumcheekascend\bumcheekascend.ash
> QUEUED 1: mcd 2
> QUEUED 2: mcd3

KoLmafia declares world peace.

> CURRENT: call scripts\dev\bumcheekascend\bumcheekascend.ash
> QUEUED 1: mcd 2
> QUEUED 2: mcd3
> QUEUED 3: mcd 6

Mafia then gives me a 36MB debug log. I thought I'd zip it up before attaching. Totally happy to accept that it's the ascend script that's doing this, but there are no errors thrown up. I have got similar errors before by doing other commands, but I was able to reproduce it this way.

View attachment DEBUG_20120320.zip
 
Last edited:
bumcheekcity

bumcheekcity

Active member
Another debug log. This one ran the script for a while, set a few variables correctly, adventures in the upper chamber, then the semirare begin counter hit and the same error as last time.

However, I amended the CounterChecker.ash that I have to print a string in the problematic part, so there's no empty section. Both my counterchecker script, which works when I execute it directly (i.e. no syntax errors or anything) and the debug log are attached.

When I execute the CounterChecker.ash script directly (it notifies Bale, asks me for a string and an int, then aborts because I'm not actually AT a semi-rare) it doesn't crash Mafia.

On a related note, the new debug logs seem in a different format to the usual ones - was a change made to them recently?
 

Attachments

  • CounterChecker.ash
    18.8 KB · Views: 25
  • DEBUG_20120321.zip
    794.5 KB · Views: 38
Veracity

Veracity

Developer
Staff member
Here's what I see in the first log:

[NORMAL] <- "mcd 10"
Entering function cli_execute

... bumcheekascend does cli_execute( "mcd 10" ) (rather than using change_mcd( 10 ), for some reason, but whatever; the ASH function invokes the CLI command itself.)

Resetting mind control device...
class net.sourceforge.kolmafia.request.MindControlRequest
Requesting: http://www.kingdomofloathing.com/inv_use.php?whichitem=2682&tuneradio=10
Retrieved: http://www.kingdomofloathing.com/inv_use.php?whichitem=2682&tuneradio=10
Redirect to: inventory.php?which=2&action=message
Requesting: http://www.kingdomofloathing.com/inventory.php?which=2&action=message
Retrieved: http://www.kingdomofloathing.com/inventory.php?which=2&action=message

... and then no sign of the page.

Instead, I see what looks like a bumrats thing for charpane.php

Executing top-level commands
Executing main function
...
Operand 1: get_property()
Param #1: "bumrats_useCHIT"
...

class net.sourceforge.kolmafia.request.RelayRequest
Requesting: http://www.kingdomofloathing.com/charpane.php
Retrieved: http://www.kingdomofloathing.com/charpane.php

... and the rest of the debug log is bumrats/CHIT executing on that page, followed by

KoLmafia declares world peace.

I do not see the HTML of the response to "inventory.php?which=2&action=message", which would have been tuning the radio
I do not see the return from the "cli_execute" of "mcd 10".

I deduce a couple things:

- You had the Relay Browser open and the Browser wanted to refresh the charpane. We fired bumrats (your master relay override) which invoked CHIT
- This charpane override happened while we were also retrieving the result of the mcd command
- after CHIT was done processing, nothing else happened until you hit the ESC key, KoLmafia declares world peace, and you then try an "mcd 2" command in the CLI, which is queued, because bumcheekascend is still executing.

The question is, why did ESC not abort your script? It was stuck, apparently, trying to retrieve the response of "inventory.php?which=2&action=message". It logged:

Retrieving server reply...
Retrieved: http://www.kingdomofloathing.com/inventory.php?which=2&action=message
10 header fields
Field: null = [HTTP/1.1 200 OK]
Field: Date = [Wed, 21 Mar 2012 07:18:45 GMT]
Field: Transfer-Encoding = [chunked]
Field: Expires = [Thu, 19 Nov 1981 08:52:00 GMT]
Field: Content-Type = [text/html; charset=UTF-8]
Field: Connection = [close]
Field: Server = [nginx/0.8.55]
Field: X-Powered-By = [PHP/5.1.6]
Field: Cache-Control = [no-store, no-cache, must-revalidate, post-check=0, pre-check=0]
Field: Pragma = [no-cache]

...and that was the end of it. It should have done this in GenericRequest:

this.responseText = new String( ByteBufferUtilities.read( istream ), "UTF-8" );
...
this.processResponse();
...
RequestLogger.updateDebugLog( text );

i.e., we should have seen the response text. It is as if it is simply hanging on the read().

I have no clue.
 
bumcheekcity

bumcheekcity

Active member
Code: 
> use chapter 5

Using 1 CRIMBCO Employee Handbook (chapter 5)...
You acquire an item: CRIMBCO Employee Handbook (chapter 5) (used)
You learned a new skill: Managerial Manipulation
Finished using 1 CRIMBCO Employee Handbook (chapter 5).

> use crimbo candy cook

You need 1 more Crimbo Candy Cookbook to continue.

> mcd 4

Resetting mind control device...
KoLmafia declares world peace.

> adv 2 pantry

KoLmafia declares world peace.

> adv 2 pantry


KoLmafia declares world peace.
> call scripts\dev\bumcheekascend\snapshot.ash

KoLmafia declares world peace.

> CURRENT: call scripts\dev\bumcheekascend\snapshot.ash
> QUEUED 1: mcd 8

> mcd 4

Resetting mind control device...
Mind control device reset.

I managed to get the ESCAPE key to not immediately abort the script. The relay browser was open, but I wasn't using it at the time deliberately, and I disabled bUMRATS and deleted all other /relay/ scripts. I'll keep trying to catch it, and disable the relay scripts to see if that's the issue.
 

Attachments

  • DEBUG_20120321.zip
    856.4 KB · Views: 48
bumcheekcity

bumcheekcity

Active member
This time the CLI just locked up completely. I entered commands and hit ENTER and they disappeared without anything happening in the CLI.
 

Attachments

  • DEBUG_20120321.txt
    1.9 MB · Views: 154
Veracity

Veracity

Developer
Staff member
It's always crapping out setting the detuned radio. The end of your debug log:

Code: 
> mcd 7

Resetting mind control device...
class net.sourceforge.kolmafia.request.MindControlRequest
Connecting to inv_use.php...

Requesting: http://www.kingdomofloathing.com/inv_use.php?whichitem=2682&tuneradio=7
4 request properties

Field: Cookie = [PHPSESSID=bp0cd6465api4sd1li2gm7pi84]
Field: User-Agent = [KoLmafia v15.1]
Field: Connection = [close]
Field: Content-Type = [application/x-www-form-urlencoded]

Retrieving server reply...

Retrieved: http://www.kingdomofloathing.com/inv_use.php?whichitem=2682&tuneradio=7

11 header fields
Field: null = [HTTP/1.1 302 Found]
Field: Date = [Wed, 21 Mar 2012 21:48:38 GMT]
Field: Content-Length = [0]
Field: Expires = [Thu, 19 Nov 1981 08:52:00 GMT]
Field: Location = [inventory.php?which=&action=message]
Field: Content-Type = [text/html; charset=UTF-8]
Field: Connection = [close]
Field: Server = [nginx/0.8.55]
Field: X-Powered-By = [PHP/5.1.6]
Field: Cache-Control = [no-store, no-cache, must-revalidate, post-check=0, pre-check=0]
Field: Pragma = [no-cache]

Connecting to inventory.php...

Requesting: http://www.kingdomofloathing.com/inventory.php?which=&action=message
3 request properties

Field: Cookie = [PHPSESSID=bp0cd6465api4sd1li2gm7pi84]
Field: User-Agent = [KoLmafia v15.1]
Field: Connection = [close]

Retrieving server reply...

Retrieved: http://www.kingdomofloathing.com/inventory.php?which=&action=message

10 header fields
Field: null = [HTTP/1.1 200 OK]
Field: Date = [Wed, 21 Mar 2012 21:48:39 GMT]
Field: Transfer-Encoding = [chunked]
Field: Expires = [Thu, 19 Nov 1981 08:52:00 GMT]
Field: Content-Type = [text/html; charset=UTF-8]
Field: Connection = [close]
Field: Server = [nginx/0.8.55]
Field: X-Powered-By = [PHP/5.1.6]
Field: Cache-Control = [no-store, no-cache, must-revalidate, post-check=0, pre-check=0]
Field: Pragma = [no-cache]
... but no response text logged. Very strange.
 
bumcheekcity

bumcheekcity

Active member
I don't know if all these issues are related, but this time mafia was happy to adventure in places if I typed "adv outskirts of the knob" (or similar) into the CLI, but the relay browser gave me nothing for adventure.php. I could visit other pages (messages.php, and the cake arena), but not adventure in the relay browser.

All relay scripts were disabled for this. Would there be anything I could do in particular to help diagnose the problem?
 

Attachments

  • DEBUG_20120321.zip
    378.7 KB · Views: 48
Veracity

Veracity

Developer
Staff member
It's something about you, and only you. What's your OS, browser, java version?

Here's something to try: turn on Preferences->Extra debugging->"Verbosely log communication between KoLmafia and browser".
 
bumcheekcity

bumcheekcity

Active member
'java' is not recognised as an internal or external command.

My Program Files (x86) folder has two jres in it, I've just noticed that. jre6 and jre7. Could that be part of the issue?

1.6.0_31

1.7.0_02

Is what they separately identify as.
 
Bale

Bale

Minion
Or if you are currently using KoLmafia you can discover the java version by checking Help -> Copyright notice.
 
E

Ethelred

Member
There was a previous thread about compatability with 1.7 and I thought that 1.7 had not yet been sanctioned. Maybe try falling back to 1.6 and see if the problem persists. Or maybe even better, wait until someone who knows what they're talking about responds.
 
fronobulax

fronobulax

Developer
Staff member
Ethelred said:
There was a previous thread about compatability with 1.7 and I thought that 1.7 had not yet been sanctioned. Maybe try falling back to 1.6 and see if the problem persists. Or maybe even better, wait until someone who knows what they're talking about responds.
Click to expand...

I persisted in thinking v1.7 had not been sanctioned and someone found a post circa Fall 2011 from V or H that said in effect "1.7 is fine. Use it. Let us know if you think otherwise." So while I have not personally upgraded to 1.7 (although I should) I would hesitate to point a finger at 1.7 unless I was in a position to help identify what worked in 1.6 but not 1.7.
 
bumcheekcity

bumcheekcity

Active member
I thought it was something to do with disabling bUMRATS, but it just happened today, although I didn't have debug logging turned on. I'll try to recreate without any relay scripts.

I just tried to log on again and the script hung at Examining equipment in storage. Debug log was running and is attached.
 

Attachments

  • DEBUG_20120323.txt
    257.7 KB · Views: 2,507
Last edited:
Veracity

Veracity

Developer
Staff member
Same symptom: we submit a request, we get a reply, but hang actually reading the response text.

Code: 
class net.sourceforge.kolmafia.request.StorageRequest
Connecting to storage.php...

Requesting: http://www.kingdomofloathing.com/storage.php?which=1
4 request properties

Field: Cookie = [PHPSESSID=d7p3od19mf4fautki9k7ml7i77]
Field: User-Agent = [KoLmafia v15.1]
Field: Connection = [close]
Field: Content-Type = [application/x-www-form-urlencoded]

Retrieving server reply...

Retrieved: http://www.kingdomofloathing.com/storage.php?which=1

10 header fields
Field: null = [HTTP/1.1 200 OK]
Field: Date = [Fri, 23 Mar 2012 18:29:24 GMT]
Field: Transfer-Encoding = [chunked]
Field: Expires = [Thu, 19 Nov 1981 08:52:00 GMT]
Field: Content-Type = [text/html; charset=UTF-8]
Field: Connection = [close]
Field: Server = [nginx/0.8.55]
Field: X-Powered-By = [PHP/5.1.6]
Field: Cache-Control = [no-store, no-cache, must-revalidate, post-check=0, pre-check=0]
Field: Pragma = [no-cache]

KoLmafia declares world peace.
Revision 10829 adds a bit more debug logging - and prints a stack trace, if we get an IOException reading the responseText.
Try again, please...
 
You must log in or register to reply here.
Top