Page 2 of 14

Re: NT Crash Thread

Posted: Wed Dec 31, 2014 4:32 pm
by zippyzee
Ah, I was thinking of the Use Item opcode when right-clicking on it. I looked it up once for something else and mistakenly thought that's what I was still seeing. I'll have to get on that when I start updating the item system again.

Re: NT Crash Thread

Posted: Wed Dec 31, 2014 6:57 pm
by Xinux

Code: Select all

 	ntdll.dll!774c8277()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]	
>	WorldServer.exe!Mutex::ReadLock() Line 99	C++
 	WorldServer.exe!UDPServer::GetClient(unsigned int account_id) Line 194	C++
 	WorldServer.exe!ChunkServer::GetClient(unsigned int account_id) Line 278	C++
 	WorldServer.exe!UDPServer::KickDupeClients(unsigned int account_id, unsigned int connection_id) Line 258	C++
 	WorldServer.exe!Net::HandleCharacterSelected(std::shared_ptr<Client> & client, PacketStruct * packet_struct) Line 390	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
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown

Code: Select all

17:24:39.686 I UDP      New client connected from 50.29.242.81:59048
17:24:39.686 I UDP      Received session request from 50.29.242.81:59048 with connection ID 568758794
17:24:39.889 I Net      New Session: Account ID: 346  Session ID: 'obn3h7k7tg53vlpkksoki50o42'
17:24:40.170 D Account  Character Created: 1
17:24:40.170 D Char     Loading character 'Mulder' (592) for account_id: 346
17:24:40.186 D Net      Sending char data for 'Mulder', New Telon
17:24:40.186 D Account  Character Destroyed: 0
17:24:42.042 D Account  Character Created: 1
17:24:42.042 I Database Successfully loaded 10 abilities into character map.
17:24:42.042 D Rules    Rule: R_Player:DefaultMovementSpeed, Value: 750.0
17:24:42.058 I Database Successfully loaded 0 items into character inventory.
17:24:42.058 D Char     Setting player online
17:24:42.510 D Char     Character Name: Mulder being Removed.
17:24:42.526 D Rules    Rule: R_Chunk:ProcessThreadSleepMS, Value: 50
17:24:42.526 D Rules    Rule: R_Chunk:RemoveSpawnDistance, Value: 17000
17:24:42.526 D Rules    Rule: R_Chunk:MaxSendSpawnDistance, Value: 8500
17:24:42.526 D Rules    Rule: R_Chunk:HearChatDistance, Value: 8500
17:24:42.526 D Rules    Rule: R_Chunk:MaxInteractionDistance, Value: 750
17:24:42.526 D Chunk    Starting chunk 'Islands of Madness' (46)
17:24:42.541 D Rules    Rule: R_Dev:LoadNPCData, Value: 1
17:24:42.666 D Spawn    673 NPCs Loaded in Chunk ID: 46
17:24:42.666 D Spawn    0 PPOs Loaded in Chunk ID: 46
17:24:42.682 D Spawn    10 Music Tracks Loaded in Chunk ID: 46
17:24:42.682 D Spawn    4 Sounds Loaded in Chunk ID: 46
17:24:42.682 D Spawn    0 Movers Loaded in Chunk ID: 46
17:24:42.900 D Account  Client Created: 2
17:24:42.900 I UDP      New client connected from 50.29.242.81:59049
17:24:42.900 I UDP      Received session request from 50.29.242.81:59049 with connection ID 622742878
17:24:43.118 I Chunk    New Session: Account ID: 346  Session ID: 'obn3h7k7tg53vlpkksoki50o42'
17:24:43.337 D Chunk     control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
17:24:43.508 D Chunk     control_text='LOGIN'
17:24:59.483 W Chunk    Camp requested from client with character==null
17:25:26.268 D Account  Client Created: 3
17:25:26.268 I UDP      New client connected from 50.29.242.81:63547
17:25:26.268 I UDP      Received session request from 50.29.242.81:63547 with connection ID 1351275907
17:25:26.486 I Net      New Session: Account ID: 346  Session ID: 'obn3h7k7tg53vlpkksoki50o42'
17:25:26.720 D Account  Character Created: 2
17:25:26.720 D Char     Loading character 'Mulder' (592) for account_id: 346
17:25:26.720 D Net      Sending char data for 'Mulder', New Telon
17:25:26.720 D Account  Character Destroyed: 1


******* Update ***********

I just updated NT to the latest revision

Re: NT Crash Thread

Posted: Sat Jan 03, 2015 3:47 pm
by Lokked
Rev 896 attempts to address 1 or 2 of the errors here. This hopefully addresses the lock being Empty and the KickDupeClients crash while iterating the Clients list.

Re: NT Crash Thread

Posted: Sat Jan 03, 2015 4:15 pm
by John Adams
Just tested 895, turning movement looks great. Inclines also look spot on. Great work!

I've got 896 on NT, stand by.

Edit: One oddity, world console shows 3 clients, but in-game it's just my 2:
[quote]clients
16:17:47.487 I UDP Account Name: , Account ID: 0, IP Address: 76.121.69.227
16:17:47.487 I UDP Account Name: johnadams1, Account ID: 1, IP Address: 68.98.218.5
16:17:47.487 I UDP Account Name: johnadams2, Account ID: 2, IP Address: 68.98.218.5[/quote]
The 1st one is merely connected to Login and not in-game, but note the detail?

This player was first to hit Login before me, but never came into the game:
[quote]16:09:17.397 D Account Client Created. Total Now: 1
16:09:17.397 I UDP New client connected from 76.121.69.227:59580
16:09:34.729 D Account Character Created. Total Now: 1
16:09:34.729 D Account Character Created. Total Now: 2
16:09:34.729 D Account Character Created. Total Now: 3
16:09:34.729 D Account Character Created. Total Now: 4
16:09:34.745 D Char Loading character 'Marie Laveau' (575) for account_id: 0
16:09:34.745 D Char Loading character 'Cordelia Foxx' (577) for account_id: 0
16:09:34.745 D Char Loading character 'Quonx xquon' (580) for account_id: 0
16:09:34.761 D Char Loading character 'Nullyn Void' (635) for account_id: 0
16:09:34.761 D Net Sending char data for 'Marie', New Telon
16:09:34.761 D Net Sending char data for 'Cordelia', New Telon
16:09:34.761 D Net Sending char data for 'Quonx', New Telon
16:09:34.776 D Net Sending char data for 'Nullyn', New Telon
16:09:34.776 D Account Character Destroyed. Total Now: 3
16:09:34.776 D Account Character Destroyed. Total Now: 2
16:09:34.776 D Account Character Destroyed. Total Now: 1
16:09:34.776 D Account Character Destroyed. Total Now: 0
16:09:37.444 D Account Character Created. Total Now: 1
16:09:37.444 D Account Character Created. Total Now: 2
16:09:37.444 D Account Character Created. Total Now: 3
16:09:37.444 D Account Character Created. Total Now: 4
16:09:37.444 D Char Loading character 'Marie Laveau' (575) for account_id: 0
16:09:37.459 D Char Loading character 'Cordelia Foxx' (577) for account_id: 0
16:09:37.459 D Char Loading character 'Quonx xquon' (580) for account_id: 0
16:09:37.459 D Char Loading character 'Nullyn Void' (635) for account_id: 0
16:09:37.459 D Net Sending char data for 'Marie', New Telon
16:09:37.459 D Net Sending char data for 'Cordelia', New Telon
16:09:37.459 D Net Sending char data for 'Quonx', New Telon
16:09:37.475 D Net Sending char data for 'Nullyn', New Telon
16:09:37.475 D Account Character Destroyed. Total Now: 3
16:09:37.475 D Account Character Destroyed. Total Now: 2
16:09:37.475 D Account Character Destroyed. Total Now: 1
16:09:37.475 D Account Character Destroyed. Total Now: 0[/quote]
Why do those all say account_id: 0 ? Surely, this player has an account if it retrieved 4 characters.

Not saying it's related to new changes, but concerned about the new timeouts. Are we killing something too soon now?

Re: NT Crash Thread

Posted: Sat Jan 03, 2015 4:40 pm
by Lokked
Yeah, that shouldn't happen. There is no account_id == 0.

So that user never logged in? Perhaps they will be kind enough to identify themselves and describe what was happening on their end.

Re: NT Crash Thread

Posted: Sat Jan 03, 2015 5:05 pm
by John Adams
[quote="Lokked"]Perhaps they will be kind enough to identify themselves and describe what was happening on their end.[/quote]
[img]http://www.netanimations.net/roflmao.gif[/img]

Re: NT Crash Thread

Posted: Sun Jan 04, 2015 1:09 pm
by John Adams
World crash during SQL query I believe:

Code: Select all

 	ntdll.dll!774f0574()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]	
 	ntdll.dll!774b2aba()	Unknown
 	ntdll.dll!77481d17()	Unknown
 	KernelBase.dll!75bc5621()	Unknown
>	WorldServer.exe!_CrtIsValidHeapPointer(const void * pUserData) Line 2036	C++
 	WorldServer.exe!_free_dbg_nolock(void * pUserData, int nBlockUse) Line 1322	C++
 	WorldServer.exe!_free_dbg(void * pUserData, int nBlockUse) Line 1265	C++
 	WorldServer.exe!free(void * pUserData) Line 49	C++
 	WorldServer.exe!_my_free()	Unknown
 	WorldServer.exe!_vio_delete()	Unknown
 	WorldServer.exe!_end_server()	Unknown
 	WorldServer.exe!_cli_safe_read()	Unknown
 	WorldServer.exe!_cli_read_rows()	Unknown
 	WorldServer.exe!_mysql_close@4()	Unknown
 	WorldServer.exe!_mysql_real_query@12()	Unknown
 	WorldServer.exe!Database::Query(const char * fmt, ...) Line 136	C++
 	WorldServer.exe!WorldDatabase::UpdateCharacterItem(std::shared_ptr<WorldCharacter> & character, ItemInfo * item) Line 3310	C++
 	WorldServer.exe!WorldCharacter::CharEquipItem(unsigned int unique_id, unsigned char unknown) Line 2199	C++
 	WorldServer.exe!ChunkServer::HandleClientMoveWornItem(std::shared_ptr<Client> & client, PacketStruct * packet) Line 2122	C++
 	WorldServer.exe!ChunkServer::ProcessPackets() Line 514	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
 	ntdll.dll!77459f72()	Unknown
 	ntdll.dll!77459f45()	Unknown
SQL Query:
[quote]UPDATE `character_items` SET `item_id_fk` = 1422103, `bag_id` = 4294967295, `current_slot` = 14, `current_equip_slot` = 6, `durability` = 100 WHERE char_id_fk = 537 AND unique_id = 9[/quote]
which runs fine in SQL GUI tool

[quote][13:04] <Moldew> I was equipping/unequipping armor on Moldew[/quote]


Log attached:

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


Re: NT Crash Thread

Posted: Sun Jan 04, 2015 1:43 pm
by Lokked
This error may not have anything to do with the SQL. This error means that a check to validate a memory space for usage has failed. It could be a double free or accessing memory that was already freed or never allocated. The culprit is usually the piece of code that did the freeing, and the error occurs in the section that tried to access the freed memory. I wonder if it's a bug with MySQL.

Re: NT Crash Thread

Posted: Sun Jan 04, 2015 3:13 pm
by Xinux
This is interesting looking at the server log and the packet collector log i just happen to be running.

Code: Select all

13:02:53.329 E UDP      Received packet with unknown protocol opcode 0x0D3D (3389) from 72.193.68.198:54526
13:02:53.329 D Char     Character Iodtester Set to Offline
13:02:53.344 I UDP      Client from 72.193.68.198:54526 set to disconnect : Application

Code: Select all

-- Client Spawn & Movement --
1/4/2015 12:02:53
192.168.0.111 -> 68.98.218.5
0000:	00 09 0D 3D 01 00 16 00 00 00 4D 0B 08 20 08 D2 ...=......M.. ..
0010:	77 56 3F 44 7D 81 86 6E 17 6C 10 2E 45 01 00 04 wV?D}..n.l..E...


-- Close Connection Packet
1/4/2015 12:02:53
68.98.218.5 -> 192.168.0.111
0000	00 05 5B C2 9A F1 00 06                         ..[.....
Notice the packet sequence getting read as the protocol opcode.

and also

[12:06] <@Xinux> The very last packet i got from the server was at 12:02:37
[12:07] <@Xinux> till it sent me the disconnect at 12:02:53

Re: NT Crash Thread

Posted: Mon Jan 05, 2015 12:50 am
by Lokked
2 Commits to help alleviate this.
Rev 897 improves robustness of KickDupeClients and fixes an issue where someone logging back in immediately after Force Close or CTD was unable to see Players (and possible NPCs) that were in their proximity when their client closed.
Rev 898 may help resolve Xinux's report above. Previously, if the Server received ANY malformed packet, it would Disconnect the client. Now, it will just ignore the packet. The occurrence will still be logged to the console, I only commented out the BeginDisconnectFromServer sequence.