Bug - Cannot Reproduce Debug log on a relay script. PLEASE HELP!

[Bale]

Using r8833. I'm trying to run my OCD relay script. This only happens with one character. Others seem able to run the relay script without trouble. ???

=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
         KoLmafia v14.3 r8833, Windows XP, Java 1.6.0_22
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
 Please note: do not post this log in the KoLmafia thread. If you
 would like the dev team to look at it, please write a bug report
 at kolmafia.us. Include specific information about what you were 
 doing when you made this and include the log as an attachment.
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
 Timestamp: Sat Dec 18 01:25:54 EST 2010
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=


Unexpected error, debug log printed.
class java.lang.NullPointerException: null
java.lang.NullPointerException
	at net.sourceforge.kolmafia.textui.parsetree.Variable.setValue(Variable.java:122)
	at net.sourceforge.kolmafia.textui.parsetree.VariableReference.setValue(VariableReference.java:108)
	at net.sourceforge.kolmafia.textui.parsetree.VariableReference.setValue(VariableReference.java:97)
	at net.sourceforge.kolmafia.textui.parsetree.ForEachLoop.executeSlice(ForEachLoop.java:163)
	at net.sourceforge.kolmafia.textui.parsetree.ForEachLoop.execute(ForEachLoop.java:109)
	at net.sourceforge.kolmafia.textui.parsetree.BasicScope.execute(BasicScope.java:451)
	at net.sourceforge.kolmafia.textui.parsetree.UserDefinedFunction.execute(UserDefinedFunction.java:129)
	at net.sourceforge.kolmafia.textui.parsetree.FunctionCall.execute(FunctionCall.java:166)
	at net.sourceforge.kolmafia.textui.parsetree.BasicScope.execute(BasicScope.java:451)
	at net.sourceforge.kolmafia.textui.parsetree.UserDefinedFunction.execute(UserDefinedFunction.java:129)
	at net.sourceforge.kolmafia.textui.Interpreter.executeScope(Interpreter.java:265)
	at net.sourceforge.kolmafia.textui.Interpreter.execute(Interpreter.java:198)
	at net.sourceforge.kolmafia.textui.Interpreter.execute(Interpreter.java:191)
	at net.sourceforge.kolmafia.KoLmafiaASH.getClientHTML(KoLmafiaASH.java:110)
	at net.sourceforge.kolmafia.KoLmafiaASH.getClientHTML(KoLmafiaASH.java:92)
	at net.sourceforge.kolmafia.request.RelayRequest.handleSimple(RelayRequest.java:1476)
	at net.sourceforge.kolmafia.request.RelayRequest.run(RelayRequest.java:1504)
	at net.sourceforge.kolmafia.LocalRelayAgent.readServerResponse(LocalRelayAgent.java:420)
	at net.sourceforge.kolmafia.LocalRelayAgent.performRelay(LocalRelayAgent.java:132)
	at net.sourceforge.kolmafia.LocalRelayAgent.run(LocalRelayAgent.java:109)

All I can tell is that I've narrowed down the problem with debug statements to this:

is_craftable: Start
Unexpected error, debug log printed.

record concoctions {
	string method;
	string mix1;
	string mix2;
};
concoctions [item] crafty;
file_to_map("concoctions.txt", crafty);
boolean [item] is_craftable;
boolean [item] is_untinkerable;

void is_craftable() {
print("is_craftable: Start");
	foreach key, value in crafty {
print("is_craftable:"+key);
		is_craftable[item_name(value.mix1)] = true;
		is_craftable[item_name(value.mix2)] = true;
		if(value.method == "COMBINE" && key != $item[bitchin meatcar])
			is_untinkerable[key] = true;
	}
print("is_craftable: End");
}

I cannot figure out why it would die there, nor why it will only die for one character! So I make some more mods to is_craftable() and get an even more bizarre output

void is_craftable() {
print("is_craftable: Start");
int i = 0;
foreach key in crafty {
	print(key); 
	i +=1;
	if( i> 4) break;
}
print("is_craftable: Intermission");
	foreach key in crafty {
		is_craftable[item_name(crafty[key].mix1)] = true;
		is_craftable[item_name(crafty[key].mix2)] = true;
		if(crafty[key].method == "COMBINE" && key != $item[bitchin meatcar])
			is_untinkerable[key] = true;
	}
print("is_craftable: End");
}

Output:

is_craftable: Start
4896
4872
17-alarm Saucepan
3vi1 pr0n m4nic0tti
4-d camera
is_craftable: Intermission
[COLOR="#ff0000"]Map modified within foreach (relay_OCD_dB_Manager.ash, line 296)[/COLOR]

As odd as it is to get items 4896 and 4872, the oddest thing is that when I run this script on other characters, those items do not appear. How the heck is file_to_map("concoctions.txt", crafty) producing a different map for different characters??

Even more horrifying, 4896 and 4872 are not items!! I cannot remove them from the map when I try.

I'm pretty sure that the error happens because crafty[4896] does not have a value, but how did it get in the map?

 

[Bale]

Incidentally, I first observed this yesterday with an earlier build of mafia. It never happened before yesterday. It is endlessly reproducible on my main character.

I cannot reproduce this on any other character so I suspect nobody else will be able to reproduce it either. Right now I have my script working, in a hobbled fashion like this:

void is_craftable() {
if(my_name() == "bale") return;
	foreach key, value in crafty {
		is_craftable[item_name(value)] = true;
		is_craftable[item_name(value)] = true;
		if(value.method == "COMBINE" && key != $item[bitchin meatcar])
			is_untinkerable[key] = true;
	}
}

That works for all my characters. The ones not named "bale" get full functionality.

 

[roippi]

Holiday log - 4896 - was added in r8832. I imagine there's some bug associated with that, though saying exactly what is a bit beyond me.

 

[Bale]

Yes, and 4872 is the glob of Blank-Out. However only one of my characters has this bug and it should be impossible for the item to show up as an integer in a map indexed by item.

(It shouldn't matter, but none of my characters have either of those items.)

 

[Veracity]

gob of Blank-O is a "SUSE" (single use) item. In other words, it is not a combination of two other items; it is created by "using" a single item. Your record has a "mix1" and a "mix2" field, but that's not relevant for that concoctions. (For that matter, all chefstaves have 5 or 6 ingredients, and wouldn't be seen by that record).

It looks like file_to_map is doing something funky with concoctions that don't have enough fields. It should probably ignore them.

Edit: Here is a test program:

record concoctions { 
    string method; 
    string mix1; 
    string mix2; 
}; 
concoctions [item] crafty; 
file_to_map("concoctions.txt", crafty);

item it = $item[ glob of Blank-Out ];
if ( crafty contains it ) {
  concoctions value = crafty[ it ];
  print( it + " is in map.");
  print( "method = " + value.method );
  print( "mix1 = \"" + value.mix1 + "\"" );
  print( "mix2 = \"" + value.mix2 + "\"" );
 } else {
  print( "No " + it + " in map.");
 }

and here is what it produces:

> crafty.ash

glob of Blank-Out is in map.
method = SUSE
mix1 = "bottle of Blank-Out"
mix2 = ""

What does that program do for your character that fails to read concoctions.txt correctly?

 

[Bale]

Thank you for the response. I'm not ignoring this on purpose, but unfortunately I won't be able to tell you until tomorrow.

 

[Bale]

I can no longer reproduce this bug. I do not know what changed to make that character work like the others.

Veracity, thanks for the help, but that program produces the same output for me that it does for you. I can only wonder what it would have done yesterday when the problem was reproducible. (Yes, I quit the program and restarted it and it still happened. I cannot imagine why it has regained sanity.)

Please mark the bug as not reproducible.