Collections - World Crash

[John Adams]

This is strange. I did collections just the other day, and don't remember seeing this problem. Maybe it's just the EQ2TC data. Anyway, a player was apparently collecting and adding items to a collection:

Code: Select all

   0: 21 00 0B 00 69 6E 76 65 - 6E 74 6F 72 79 20 33     | !...inventory 3
10:21:38 D Command: Handler: 33, COMMAND: 'info'
10:21:38 D Command: Player 'Zanifer' (6258), Command: info
   0: 1E 00 05 00 35 34 35 20 - 33                       | ....545 3
10:21:40 D Command: Handler: 30, COMMAND: 'collection_additem'
10:21:40 D Command: Player 'Zanifer' (6258), Command: collection_additem
10:21:40 D Items: Deleting item_id 6920 for player (null)

Player (null)?

Code in error:

Code: Select all

bool Client::RemoveItem(Item *item, int8 quantity) {
	EQ2Packet *outapp;

	assert(item);

	if (quantity > 0 && !item->IsBag() && item->details.count > quantity) {
		item->details.count -= quantity;
		item->save_needed = true;
	}
	else {
		database.DeleteItem(character_id, item, 0);
		player->GetPlayerItemList()->RemoveItem(item, true);
	}
	
	if ((outapp = player->SendInventoryUpdate(version))) {
		QueuePacket(outapp);
		if (item->GetItemScript() && lua_interface)
here ==>>>>			lua_interface->RunItemScript(item->GetItemScript(), "removed", item, player);
			return true;
	}

	return false;
}

Stack:

Code: Select all

 	EQ2World__Debug.exe!strlen(unsigned char * buf)  Line 69	Asm
 	EQ2World__Debug.exe!std::char_traits<char>::length(const char * _First)  Line 491 + 0x9 bytes	C++
 	EQ2World__Debug.exe!std::basic_string<char,std::char_traits<char>,std::allocator<char> >::assign(const char * _Ptr)  Line 931 + 0x9 bytes	C++
 	EQ2World__Debug.exe!std::basic_string<char,std::char_traits<char>,std::allocator<char> >::basic_string<char,std::char_traits<char>,std::allocator<char> >(const char * _Ptr)  Line 595	C++
>	EQ2World__Debug.exe!Client::RemoveItem(Item * item, unsigned char quantity)  Line 3835 + 0x29 bytes	C++
 	EQ2World__Debug.exe!Client::HandleCollectionAddItem(unsigned int collection_id, Item * item)  Line 5740	C++
 	EQ2World__Debug.exe!Commands::Process(unsigned int index, EQ2_16BitString * command_parms, Client * client)  Line 1098	C++
 	EQ2World__Debug.exe!Client::HandlePacket(EQApplicationPacket * app)  Line 1204	C++
 	EQ2World__Debug.exe!Client::Process(bool zone_process)  Line 1775 + 0xc bytes	C++
 	EQ2World__Debug.exe!ZoneServer::ClientProcess()  Line 1925 + 0x18 bytes	C++
 	EQ2World__Debug.exe!ZoneServer::Process()  Line 896	C++
 	EQ2World__Debug.exe!ZoneLoop(void * tmp)  Line 4016 + 0x8 bytes	C++
 	EQ2World__Debug.exe!_callthreadstart()  Line 259 + 0xf bytes	C
 	EQ2World__Debug.exe!_threadstart(void * ptd)  Line 243	C
 	kernel32.dll!77e6482f() 	
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	

[reefcrazed]

I am not sure if we are talking about the same thing or not. I was in Queens Colony last night on my server, and then on Xinux's server and both gave errors when trying to add to a collection.

[Scatman]

I'll take a look when I get home. Reef, can you expand on what the error was? What you did, etc? I'll try and kill 2 ratongas with one stone.

[reefcrazed]

I just tried it again from my server and no errors. I remember on yours getting a red message on the clients screen, but I do not remember the error. It was when I was picking up some collections. I was also getting a foreign key error on mine regarding inventory, like it was trying to delete a row that was tied to a foreign key. But it was letting me pick up the collections on mine.

I did notice on 7628 just now when picking up a collection it would give the item name, on 6118 it would give a question mark for the item. Maybe it is just luck of the draw though and nothing conclusive.

[John Adams]

Any bugs reported using a DoV client are invalid. Do not use this client for testing EQ2Emulator until the entire structs/opcodes have been fixed. Bad opcodes/structs will yield disasters for Emu, and we cannot chase bugs that are caused by a non-supported client. Maybe I should remove 1096 from logging in entirely...

As for the error he's getting while collecting, it will likely be that there is no item associated with that node. That happens because I only set up a few for testing. Not all nodes have items linked, and this error is likely data... or in my ProcessHarvest() randomizers.

[reefcrazed]

I understand that John, and was not trying to create extra work.

[John Adams]

I understand that John, and was not trying to create extra work.

Don't take my "text" incorrectly. I am not scolding. Just trying to educate newer members of the team.

You'll know when I scold... cuz it'll come in the form of a PM

[Scatman]

The (null) is a bad printf formatter and *might* be the cause of the crash. The LogWrite that is wrong is in WorldDatabase::DeleteItem line 884.

Code: Select all

LogWrite(ITEM__DEBUG, "Items", "Deleting item_id %lu for player %s", item->details.item_id, type, char_id);

%s is being used for char_id which is an int32. This might be why we see those strlen()'s in the stack trace because it's trying to calculate the length of a string at memory location=char_id which is probably too low to be in valid memory space. I can change this once I get home and commit it.

[John Adams]

Scat, thanks for looking at this. I need to learn what data can go into my LogWrites better Maybe we need to set up gentler "traps" around these functions so even I cannot mess it up;)

I can fix the code, if you can educate me how to tell what data types go into what string parsers. I get the normal ones, %s string, %i int, but wtf is this item_details->blahwhothefuckknows data if I mouse over, and it says "char", shouldn't that be a damn non-int?

[reefcrazed]

The (null) is a bad printf formatter and *might* be the cause of the crash. The LogWrite that is wrong is in WorldDatabase::DeleteItem line 884.

Code: Select all

LogWrite(ITEM__DEBUG, "Items", "Deleting item_id %lu for player %s", item->details.item_id, type, char_id);

%s is being used for char_id which is an int32. This might be why we see those strlen()'s in the stack trace because it's trying to calculate the length of a string at memory location=char_id which is probably too low to be in valid memory space. I can change this once I get home and commit it.

Not a coder, so maybe I am talking out of my ass here.

Code: Select all

LogWrite(ITEM__DEBUG, "Items", "Deleting item_id %lu for player %s", item->details.item_id, type, char_id);

I would think you would leave the %s and have it go to the character, and not the char_id anyway. I would think you would want a descriptive name instead of the characters ID, which is an int32.

If I am out of line, just smack me and tell me to go back into my cave.

[Scatman]

You're right. I can make a post about printf formatters.

[John Adams]

I just realized something, even regardless of string types.

Code: Select all

"Deleting item_id %lu for player %s", item->details.item_id, type, char_id

There are 3 params, but only 2 formatters. Isn't that alone a problem? This is obviously one of my "mid-logs and got distracted" moments, becuase normally I do "for player '%s' (%u)" for player name and ID.

Oops.

[John Adams]

What the F? How did this bug slip back in here?

Someone else playing with Collections, causes crash. Pretty sure Test is running current code with the printf() fixes in place. I will check that. Too bad the f'n callstack can't point out what's wrong?

Code: Select all

 	EQ2World.exe!std::basic_string<char,std::char_traits<char>,std::allocator<char> >::basic_string<char,std::char_traits<char>,std::allocator<char> >(const char * _Ptr)  Line 594 + 0x20 bytes	C++
>	EQ2World.exe!Client::RemoveItem(Item * item, unsigned char quantity)  Line 3835 + 0x2a bytes	C++
 	EQ2World.exe!Client::QueuePacket(EQ2Packet * app)  Line 203 + 0x3e bytes	C++
 	EQ2World.exe!WorldDatabase::LoadRuleSets()  + 0x8438 bytes	C++
 	EQ2World.exe!Commands::Process(unsigned int index, EQ2_16BitString * command_parms, Client * client)  Line 1098	C++

Log:

Code: Select all

22:19:02 D Command: Handler: 33, COMMAND: 'info'
22:19:02 D Command: Player 'Bwotha' (6334), Command: info
22:19:03 D Combat: Clearing looters for spawn 'Gonk'
22:19:03 D Combat: Clearing looters for spawn 'Durg'
   0: 1E 00 05 00 35 35 31 20 - 34                       | ....551 4
22:19:03 D Command: Handler: 30, COMMAND: 'collection_additem'
22:19:03 D Command: Player 'Bwotha' (6334), Command: collection_additem
22:19:03 D Items: Deleting item_id 2922 for player 106

remove_item.jpg

[John Adams]

Found it. SCATMAN!!! Tell me what's going on here, because I don't think this code has changed in a year.

Code: Select all

bool Client::RemoveItem(Item *item, int8 quantity) {
	EQ2Packet *outapp;

	assert(item);

	if (quantity > 0 && !item->IsBag() && item->details.count > quantity) {
		item->details.count -= quantity;
		item->save_needed = true;
	}
	else {
		database.DeleteItem(character_id, item, 0);
		player->GetPlayerItemList()->RemoveItem(item, true);
	}
	
	if ((outapp = player->SendInventoryUpdate(version))) {
		QueuePacket(outapp);
		if (item->GetItemScript() && lua_interface)
			lua_interface->RunItemScript(item->GetItemScript(), "removed", item, player);
		return true;
	}

	return false;
}

Edit: Well, after analyzing the balls out of this one little function, I come to conclude something's jacked up. The code in here hasn't changed since Scat first implemented it in 1325, yet all of a sudden, if I have 1, unstacked item I am adding to a collection, the player->GetPlayerItemList()->RemoveItem(item, true); turns the Item* item into a <Bad Ptr>, but the function doesn't exit there and continues down to if (item->GetItemScript() && lua_interface), which it also seems to pass then dies on lua_interface->RunItemScript(item->GetItemScript(), "removed", item, player);

What fixed it: adding return true right after the player->GetPlayerItemList()->RemoveItem(item, true); line. Seems to work fine now.

[Trahelion]

I still get a "Failed to collect anything from ?" every time I try to pick one up.

On the plus side I get trade-skill mats, which I used to not get back in the day, thought not as much as live.

Is it a client end problem?