Page 1 of 14

NT Crash Thread

Posted: Tue Dec 23, 2014 1:12 pm
by Xinux

Code: Select all

>	WorldServer.exe!Net::HandleCharacterSelected(std::shared_ptr<Client> & client, PacketStruct * packet_struct) Line 384	C++
 	WorldServer.exe!Net::Process() Line 159	C++
 	WorldServer.exe!main(int argc, char * * argv) Line 189	C++
 	WorldServer.exe!__tmainCRTStartup() Line 241	C
 	WorldServer.exe!mainCRTStartup() Line 164	C
 	kernel32.dll!75c2338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown


Here is the log file

[The extension txt has been deactivated and can no longer be displayed.]


Re: NT Crash Thread

Posted: Tue Dec 23, 2014 7:16 pm
by Lokked
This exact crash is a recurring issue of late. We have NEVER had a crash in this function until the past few weeks or perhaps a month.

Does anyone know what changes were made to this function or functions within this function?

Re: NT Crash Thread

Posted: Tue Dec 23, 2014 9:42 pm
by Lokked
The crash happens in this function, but is not the fault of this function, just a symptom of the problem. As is obvious at the last several pages of the log, this crash is happening because the Database is being dropped and unable to perform queries. This causes HandleCharacterSelected() to fail. I have added a countermeasure to prevent a crash in HandleCharacterSelected(), but this does not resolve the reason the database is being dropped (I don't have better terminology for what's happening):

Code: Select all

22:42:16.034 E Database Error running MySQL query (2013): Lost connection to MySQL server during query
DELETE FROM `character_titles` WHERE char_id_fk=619
22:42:16.034 E Char     SaveCharacter: Failed to save character titles at c:\vgoemu\src\world\worlddatabase.cpp:2061
I'll post the 2 functions where this may be happening. These may or may not be the culprit. It either hangs on the previous query, which is:

Code: Select all

bool WorldDatabase::SaveCharacterDetails(shared_ptr<WorldCharacter>& character) {
	bool result = false;

	if (!character) {
		return(false);
	}

	result = database.Query("UPDATE `character_details` "
									"SET `title_show`=%d, `title_prefix`=%d, `title_suffix`=%d "
									"WHERE char_id_fk=%u", character->GetTitleShow(), character->GetTitleCurrentPrefix(), character->GetTitleCurrentSuffix(), character->GetCharacterID());

	if (!result) {
		return(false);
	}

	return(true);
}

Code: Select all

bool WorldDatabase::SaveCharacterTitles(shared_ptr<WorldCharacter>& character) {
	uint32_t char_id = 0;
	vector<uint32_t> titles;
	string query;
	char buffer[64];		// Must be long enough to hold all of the data below
	bool result = false;

	if (!character) {
		return(false);
	}

	// Drop all titles for this character, this allows for removing a title
	result = database.Query("DELETE FROM `character_titles` WHERE char_id_fk=%d", character->GetCharacterID());
	if (!result) {
		return(false);
	}

	// Just return if there are no titles to save
	if (character->GetTitleCount() == 0) {
		return(true);
	}

	// Get some info
	titles = character->GetTitles();
	char_id = character->GetCharacterID();

	// Start the query string
	query = "INSERT IGNORE INTO `character_titles` (`char_id_fk`,`title_id_fk`) VALUES ";

	// Add all of the character titles to the query string
	for (uint32_t i=0; i<character->GetTitleCount(); i++) {
		snprintf(buffer, sizeof(buffer), "('%d','%d'),", char_id, titles.at(i));
		query.append(buffer);
	}
	query.pop_back();

	// Run the query
	result = database.Query(query.c_str());
	if (!result) {
		return(false);
	}

	return(true);
}
Another thing I noticed is that the WorldCharacter object being processed at the time of these failures is empty, or incomplete in some way. This is indicated by this failure, right after these query failures:

Code: Select all

22:42:16.050 E Char     SaveCharacter: Failed to get character chunk at c:\vgoemu\src\world\worlddatabase.cpp:2083
This means we are unable to get the WorldCharacter's chunk, used in this failure reporting section:

Code: Select all

	if (error && character->GetIsOnline()) {
		// We need to tell the client if there was a failure, the real game did
		chunk = character->GetCurrentChunk();
		if (!chunk) {
			LogError(LOG_CHARACTER, 0, "SaveCharacter: Failed to get character chunk at %s:%u", __FILE__, __LINE__);
			return;
		}
		chunk_client = chunk->GetClient(character->GetAccountID());
		if (!chunk_client) {
			LogError(LOG_CHARACTER, 0, "SaveCharacter: Failed to get character client at %s:%u", __FILE__, __LINE__);
			return;
		}

		// Now send the error message
		chunk_client->SendMessageFromServer("<color=red>Failed to save your character. You should relog now.");
	}
	else {
		// Set to log_level 2 because with many players it will get spammy
		LogDebug(LOG_CHARACTER, 2, "Saved character '%s' (%u) data.", character->GetDisplayName().c_str(), character->GetCharacterID());
	}
Somewhere along the way, the WorldCharacter object is being used while being empty. As mentioned, Commit 888 resolves one crash possibility, but NOT the fact that these queries all start to fail at some point.

Re: NT Crash Thread

Posted: Fri Dec 26, 2014 3:10 am
by Lokked
While the turkey was cooking (Merry Christmas, btw!), I started coding in a set of R_Dev rules to enable and disable all processing related to various systems.

I'm working on: Abilities, Attributes, Factions, Inventory, Titles and Combat at this time. Let me know if you think there are more systems which should be encompassed in this idea.

This is a debug-build only feature (release will glaze over these rule checks), and it will account for ALL processing done on these systems (Load, Save and intermediate processing). For example, if Abilities are turned off, no ability load queries, character save queries involving abilities, nor Ability-related packets will be processed.

This will help to stress test specific systems. This is becoming necessary because we aren't just dealing with 1 dev adding one system at a time, we have multiple devs adding multiple systems at the same time, and everything is becoming muddy,

The strategy I'm taking is a rule for each system (0 = disable, 1 = enable) and this in relevant areas of the applicable classes:

Code: Select all

#ifdef VG_DEBUG
    If (ruleXXX == 0) {
        // do something, or perhaps nothing
    } else
#endif
    {
        // regular code section, now enclosed in this extra brace.
    }
If the VG_DEBUG flag is on (it's set up to be in the debug platform config in VS and in the makefile), the whole rule check is not compiled.

If anyone has a better way to implement this, I'll use it. I just went with whatever came to my head first.

Anything that is only done once, such as add starter abilities on character creation, is not encompassed by this. We can't have people creating characters while Abilities is turned off and never getting their starter abilities for that character.

Re: NT Crash Thread

Posted: Sat Dec 27, 2014 11:19 am
by Xinux

Code: Select all

 	WorldServer.exe!std::_Fetch_add_seq_cst_2(volatile unsigned short * _Tgt, unsigned short _Value) Line 1166	C++
 	WorldServer.exe!std::_Atomic_fetch_add_2(volatile unsigned short * _Tgt, unsigned short _Value, std::memory_order _Order) Line 1188	C++
 	WorldServer.exe!std::atomic_fetch_add_explicit(std::atomic_ushort * _Atom, unsigned short _Value, std::memory_order _Order) Line 1175	C++
 	WorldServer.exe!std::atomic_ushort::fetch_add(unsigned short _Value, std::memory_order _Order) Line 1394	C++
 	WorldServer.exe!Client::GetAndIncrementServerSequence() Line 230	C++
 	WorldServer.exe!Client::PushOutgoing(SOEProtocolData * data, bool dump_packet) Line 359	C++
 	WorldServer.exe!Client::QueuePacket(SOEProtocolData * data, bool dump_packet) Line 293	C++
 	WorldServer.exe!WorldCharacter::LeaveAllChatChannels(bool send_packets) Line 277	C++
>	WorldServer.exe!ChunkServer::DisconnectChunkClient(std::shared_ptr<Client> chunk_client, unsigned short reason_id) Line 3999	C++
 	WorldServer.exe!CampTimers::Check(ChunkServer * chunk_server) Line 250	C++
 	WorldServer.exe!ChunkServer::Process() Line 236	C++
 	WorldServer.exe!ChunkProcessThread(void * data) Line 119	C++
 	WorldServer.exe!ThreadRun(void * arg) Line 77	C++
 	WorldServer.exe!_callthreadstart() Line 255	C
 	WorldServer.exe!_threadstart(void * ptd) Line 239	C
 	kernel32.dll!75c2338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown

Code: Select all

03:14:13.855 I UDP      Client from 58.167.199.128:55224 set to disconnect : Timeout
03:14:14.323 D Char     Character oooom Set to Offline
03:14:14.323 I UDP      Client from 58.167.199.128:55201 set to disconnect : Timeout
03:14:18.925 I UDP      Client from 58.167.199.128:55224 has been removed.
03:14:18.925 D Account  Client Destroyed: 1
03:14:18.972 I Chunk    Starting chunk shutdown timer for Isle of Dawn.
03:14:19.393 I UDP      Client from 58.167.199.128:55201 has been removed.
03:14:19.393 D Account  Client Destroyed: 0
03:14:39.752 D Account  Client Created: 1
03:14:39.752 I UDP      New client connected from 58.167.199.128:55771
03:14:39.752 I UDP      Received session request from 58.167.199.128:55771 with connection ID 2011221807
03:14:40.407 I Net      New Session: Account ID: 72  Session ID: '47ad2bmtf8h48h4ntpu1o9s3g2'
03:14:40.953 D Account  Character Created: 2
03:14:40.953 D Account  Character Created: 3
03:14:40.953 D Char     Loading character 'darknessfell' (257) for account_id: 72
03:14:40.953 D Char     Loading character 'oooom' (258) for account_id: 72
03:14:40.968 D Net      Sending char data for 'darknessfell', New Telon
03:14:40.968 D Net      Sending char data for 'oooom', New Telon
03:14:40.968 D Account  Character Destroyed: 2
03:14:40.968 D Account  Character Destroyed: 1
03:14:47.755 D Char     Character Name: oooom being Removed.
03:14:50.126 D Account  Client Created: 2
03:14:50.126 I UDP      New client connected from 58.167.199.128:55789
03:14:50.126 I UDP      Received session request from 58.167.199.128:55789 with connection ID 5353942
03:14:50.157 I Chunk    Chunk shutdown cancelled for Isle of Dawn.
03:14:51.826 I Chunk    New Session: Account ID: 72  Session ID: '47ad2bmtf8h48h4ntpu1o9s3g2'
03:14:53.714 D Chunk     control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
03:14:54.354 D Chunk     control_text='LOGIN'
03:15:00.110 D Chunk     control_text='JOIN'
03:15:00.172 D Char     Loaded 8 HotButton(s) for player oooom (258)
03:15:13.604 D UDP      Filtered out a duplicate packet bunch. Sequence=0x0900.
03:16:15.583 D Chunk    Camp started for character 'oooom'
03:16:26.004 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:26.878 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:27.065 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:27.471 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:27.673 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:28.032 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:28.282 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:28.547 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:29.031 E Chunk    Unhandled opcode 0x000000D0 (208) from 58.167.199.128
03:16:33.773 I UDP      Client from 58.167.199.128:55771 set to disconnect : Timeout
03:16:35.988 D Chunk    Camping out character 'oooom'
03:16:37.611 D Char     Character oooom Set to Offline

Re: NT Crash Thread

Posted: Mon Dec 29, 2014 12:49 am
by Xinux

Code: Select all

>	WorldServer.exe!Net::HandleCharacterSelected(std::shared_ptr<Client> & client, PacketStruct * packet_struct) Line 384	C++
 	WorldServer.exe!Net::Process() Line 159	C++
 	WorldServer.exe!main(int argc, char * * argv) Line 189	C++
 	WorldServer.exe!__tmainCRTStartup() Line 241	C
 	WorldServer.exe!mainCRTStartup() Line 164	C
 	kernel32.dll!75c2338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown
attaching the log

[The extension log has been deactivated and can no longer be displayed.]


Re: NT Crash Thread

Posted: Mon Dec 29, 2014 1:05 am
by Lokked
Re: _Fetch_add_seq_cst_2: The Client object has been removed somehow. The only way that function will fail is if there is no object.

Re: HandleCharacterSelected: Is NT running on Rev 888+? 888 Should be a bandaid for this.

Re: NT Crash Thread

Posted: Wed Dec 31, 2014 11:20 am
by Xinux

Code: Select all

>	WorldServer.exe!WorldCharacter::CharEquipItem(unsigned int unique_id, unsigned char unknown) Line 2118	C++
 	WorldServer.exe!ChunkServer::HandleClientMoveWornItem(std::shared_ptr<Client> & client, PacketStruct * packet) Line 2067	C++
 	WorldServer.exe!ChunkServer::ProcessPackets() Line 522	C++
 	WorldServer.exe!ChunkPacketThread(void * data) Line 132	C++
 	WorldServer.exe!ThreadRun(void * arg) Line 77	C++
 	WorldServer.exe!_callthreadstart() Line 255	C
 	WorldServer.exe!_threadstart(void * ptd) Line 239	C
 	kernel32.dll!75c2338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown

Code: Select all

10:37:40.072 I UDP      New client connected from 98.220.34.63:56125
10:37:40.072 I UDP      Received session request from 98.220.34.63:56125 with connection ID 718927529
10:37:40.290 I Chunk    New Session: Account ID: 95  Session ID: '2seqj2qv342reahlvfvk3ti5k0'
10:37:40.509 D Chunk     control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
10:37:40.665 D Chunk     control_text='LOGIN'
10:37:45.189 D Chunk     control_text='JOIN'
10:37:45.298 D Char     Loaded 7 HotButton(s) for player Luna (731)
10:37:59.682 E Chunk    Unhandled opcode 0x000000D0 (208) from 98.220.34.63
10:38:12.537 D Command  Player 'Luna' used command '.item' (37)
10:38:29.432 D Command  Player 'Luna' used command '.item:list' (38)
10:38:29.432 D Rules    Rule: R_Items:MaxItemsReturned, Value: 200
10:38:31.024 I Command  Player Luna obtained info about item with keyword(s) (scout's)
10:39:16.467 D Command  Player 'Luna' used command '.item:add' (39)
10:39:18.729 I Command  Player Luna gave item 'Scout's Bow of Battle' (1433063) to Player Luna.
10:40:07.792 D Command  Player 'Luna' used command '.item:add' (39)
10:40:10.303 I Command  Player Luna gave item 'Scout's Sleeves' (1423010) to Player Luna.
10:40:22.206 D Char     Saved character 'Luna' (731) data.
10:40:55.981 D Command  Player 'Luna' used command '.item:add' (39)
10:40:56.839 I Command  Player Luna gave item 'Scout's Tunic' (1433056) to Player Luna.
10:41:15.169 D Command  Player 'Luna' used command '.item:add' (39)
10:41:16.292 I Command  Player Luna gave item 'Scout's Boots' (1433059) to Player Luna.
10:41:33.406 D Command  Player 'Luna' used command '.item:add' (39)
10:41:33.422 I Command  Player Luna gave item 'Scout's Cloak' (1433117) to Player Luna.
10:41:49.802 D Command  Player 'Luna' used command '.item:add' (39)
10:41:49.817 I Command  Player Luna gave item 'Scout's Headgear' (1433054) to Player Luna.
10:42:24.527 D Command  Player 'Luna' used command '.item:add' (39)
10:42:27.164 I Command  Player Luna gave item 'Scout's Braided Belt' (1432920) to Player Luna.
10:43:19.003 D Command  Player 'Luna' used command '.item:add' (39)
10:43:19.019 I Command  Player Luna gave item 'Scout's Shortsword of Battle' (1423285) to Player Luna.
10:44:12.856 D Command  Player 'Luna' used command '.item:add' (39)
10:44:12.871 I Command  Player Luna gave item 'Scout's Longsword' (1432931) to Player Luna.
10:44:57.597 E Packet   Server packet struct (type=2) (client) with opcode 0x00000114 (276) not found
10:44:57.597 E Chunk    Unhandled opcode 0x00000114 (276) from 98.220.34.63
10:44:58.112 E Packet   Server packet struct (type=2) (client) with opcode 0x00000113 (275) not found
10:44:58.112 E Chunk    Unhandled opcode 0x00000113 (275) from 98.220.34.63
10:45:24.305 D Char     Saved character 'Luna' (731) data.
10:45:24.539 E Packet   Server packet struct (type=2) (client) with opcode 0x00000090 (144) not found
10:45:24.539 E Chunk    Unhandled opcode 0x00000090 (144) from 98.220.34.63
10:45:31.481 I Chunk    ChunkServer::HandleClientInvMove swapped 3 with 9
10:45:35.505 E Packet   Server packet struct (type=2) (client) with opcode 0x00000090 (144) not found
10:45:35.505 E Chunk    Unhandled opcode 0x00000090 (144) from 98.220.34.63
10:45:37.409 E UDP      Received packet with unknown protocol opcode 0x08CD (2253) from 98.220.34.63:56125
10:45:38.703 D Char     Character Luna Set to Offline
10:45:38.703 I UDP      Client from 98.220.34.63:56125 set to disconnect : Application
10:45:38.719 D Account  Client Created: 3
10:45:38.719 I UDP      New client connected from 98.220.34.63:56125
opcode 144 is OP_ClientUnequipItem

Re: NT Crash Thread

Posted: Wed Dec 31, 2014 3:33 pm
by zippyzee
This code starts the chain (in chunkserver):

Code: Select all

auto target_character = client->GetCharacter();

	unique_id = packet->GetUInt32("unique_id");
	unknown2 = packet->GetUInt8("unknown2");
	//unknown3 = packet->GetUInt8("unknown3");

	target_character->CharEquipItem(unique_id, (uint8_t) unknown2);
and this finishes it (in worldcharacter):

Code: Select all

// Get the item
	item = char_inventory->GetItems()[unique_id];
This should look for the item (mapped by unique_id) in the character's inventory. There is a check on the next line to see if the item was actually found, and bails out if not. The code crash occurred on the GetItems() call.

Either I need to be more explicit in searching the map, using map.find(), or the target_character (and associated inventory) is null. I would guess the latter. I can add a check in the calling function to see if the client->getCharacter() actually returned a character, or a check in the next function to see if the inventory is null.

This looks like something in the same pattern where the character disappears. Or, it could just be some issue with the inventory or item system.

I added an ITEM debug category a while back (it was actually already there) but it needs to be enabled in vgemu-world.xml for more logging if it is the item system causing the issue.

I wasn't aware of the client_unequip opcode. I've just been handling it as players move items around in inventory. I'm not sure I've seen it in testing; I'll have to see if it has always been doing that or there is a way to unequip items that I hadn't used in game.

Re: NT Crash Thread

Posted: Wed Dec 31, 2014 4:18 pm
by Xinux
You can equip/unequip items two way's either by right clicking the item or by dragging it with your mouse.