World Bugs and Crashes List

[John Adams]

Foof, I think I see what's going on with the spam disconnects. My toon initially logged in to Hathor Zhi and sat there for some time. I then ran him through Pankor Zhi (2nd chunk), and finally out into Lomshir (3rd chunk). The first 2 chunks shut down accordingly, and I sat in Lomshir for 30 mins.

Then, I exited the client (X, not camp). This is what the console said after a minute or so:

10:17:56.166 I Chunk    Starting chunk shutdown timer for Hathor Zhi.
10:22:15.852 I Chunk    Shutdown timer expired. Shutting down Pankor Zhi.
10:22:56.211 I Chunk    Shutdown timer expired. Shutting down Hathor Zhi.
10:47:36.325 I UDP      Client from 68.98.218.5:46479 set to disconnect : Timeout
10:47:37.340 I UDP      Client from 68.98.218.5:46479 has been removed.
10:47:41.255 I UDP      Client from 68.98.218.5:50144 set to disconnect : Timeout
10:47:41.396 I UDP      Client from 68.98.218.5:26653 set to disconnect : Timeout
10:47:42.269 I UDP      Client from 68.98.218.5:50144 has been removed.
10:47:42.285 I Chunk    Starting chunk shutdown timer for Lomshir.
10:47:42.410 I UDP      Client from 68.98.218.5:26653 has been removed.

This is telling me 3 connections from my IP shut down after the last one scheduled disconnect. Why are we holding open connections to chunks that are shut down or that we are no longer in? (46479, 50144), because 26653 was probably my current chunk/port.

[theFoof]

[quote="John Adams"]This is telling me 3 connections from my IP shut down after the last one scheduled disconnect. Why are we holding open
connections to chunks that are shut down or that we are no longer in? (46479, 50144), because 26653 was probably my current chunk/port.[/quote]

We don't. One of those connections was your world connection, another was an active chunk connection. The 3rd was probably a dupe connection the client made, which is related to this:

[quote="theFoof"]I was able to reproduce this with local clients and what happened was after one of the connection dropped, sometimes the remaining client would just change what port it was using as it's source. The new client however never gets a session request or anything like that so we can't really reference it very well in code and it breaks a lot of things.

So we have to figure out if this is normal and there's just a packet the client sends out to let the server know, or more likely because of the timing it's reacting to something the server is doing. It's probably going to be socket related, but I don't know for sure.[/quote]

[John Adams]

Welp, take off that party hat. Apparently me logging in multiple clients and running around and camping and quitting and all the things that caused issues yesterday, works fine.

The second a WAN connection came in, we're back to deadlocks and crashes.

Stack:

Code: Select all

>	WorldServer.exe!std::_Debug_message(const wchar_t * message, const wchar_t * file, unsigned int line) Line 15	C++
 	WorldServer.exe!std::deque<ClientSocketData *,std::allocator<ClientSocketData *> >::pop_front() Line 1457	C++
 	WorldServer.exe!UDPServer::HandleWriteHelper(ClientSocketData * data, unsigned __int64 now) Line 516	C++
 	WorldServer.exe!UDPServer::ResendPackets(std::shared_ptr<Client> & client) Line 1072	C++
 	WorldServer.exe!UDPServer::HandleWrite() Line 482	C++
 	WorldServer.exe!WriterThread(void * data) Line 127	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!7647338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77ce9f72()	Unknown
 	ntdll.dll!77ce9f45()	Unknown

btw, I have a very busy day today so I cannot trap crashes all day. You guys will need to debug this on your own servers. Start your server, let people log in, and you will see the same issues I do. If not, then there's something wrong with running Login+World from the same IP over WAN, which seems inconceivable.

Meanwhile, I'll re-apply the "workaround" of shutdown timers on New Telon for now.

[John Adams]

Set my zones to 60s timeouts this time, and after a few hours crashing started again.

Code: Select all

>	WorldServer.exe!std::_Debug_message(const wchar_t * message, const wchar_t * file, unsigned int line) Line 15	C++
 	WorldServer.exe!std::deque<ClientSocketData *,std::allocator<ClientSocketData *> >::pop_front() Line 1457	C++
 	WorldServer.exe!UDPServer::HandleWriteHelper(ClientSocketData * data, unsigned __int64 now) Line 516	C++
 	WorldServer.exe!UDPServer::ResendPackets(std::shared_ptr<Client> & client) Line 1072	C++
 	WorldServer.exe!UDPServer::HandleWrite() Line 482	C++
 	WorldServer.exe!WriterThread(void * data) Line 127	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!7647338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77ce9f72()	Unknown
 	ntdll.dll!77ce9f45()	Unknown

Something different in the dialog:
[quote]Debug Assertion Failed!

Program: C:\vgoemu\dev\VCProjects\..\..\bin\world\WorldServer.exe
File: c:\program files (x86)\microsoft visual studio 11.0\vc\include\deque
Line: 1457

Expression: deque empty before pop

For information on how your program can cause an assertion
failure, see the Visual C++ documentation on asserts.

(Press Retry to debug the application)
'WorldServer.exe' (Win32): Loaded 'C:\Windows\SysWOW64\ole32.dll'. Cannot find or open the PDB file.
First-chance exception at 0x7660C42D in WorldServer.exe: Microsoft C++ exception: unsigned int at memory location 0x0546F4F8.
First-chance exception at 0x7660C42D in WorldServer.exe: Microsoft C++ exception: unsigned int at memory location 0x0546F4F8.
The thread 0xcf8 has exited with code 0 (0x0).
The thread 0xde0 has exited with code 0 (0x0).
The thread 0xbd0 has exited with code 0 (0x0).
WorldServer.exe has triggered a breakpoint.[/quote]

Things were fine for hours, then another client came in (total of 3, including 1 of mine).

[quote]16:25:35.916 I UDP New client connected from 24.59.239.44:49370
16:25:35.916 I UDP Received session request from 24.59.239.44:49370 with connection ID 564675647
16:25:36.166 I Chunk New Session: Account ID: 113 Session ID: 'u0isic344aek3ed330l7e2d4b0'
16:25:36.431 D Chunk control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
16:25:36.665 D Chunk control_text='LOGIN'
16:25:43.139 D Chunk control_text='JOIN'
16:25:43.155 D Rules Rule: R_Player:DefaultMovementSpeed, Value: 750.0
16:26:06.619 E Mutex Timeout trying to acquire mutex Client::m_SentPackets's write lock lock after 10000 milliseconds

16:26:06.634 E UDP Read timed out after 2000 milliseconds! Disconnecting this client to be safe.
.
.
.[/quote]
Pages of timeouts while the world was crashing for 20 mins. I knew something was wrong (and went to look) when my /who didn't work anymore.

[John Adams]

For those new devs on board, this is the current working thread of all the issues between revs 579 and 605.


One more thing to add to the pile, which you should not spend time investigating just yet because it may already be solved post 579 - connections are not disconnecting properly (in code) so it never seems to hit my decrementer for who's online -

I saw this and got excited. Then realized, there really was only 1 person online Just a note to myself to look into this when I return.

[John Adams]

Crash of the Day (been a while, that's good news).

Stack:

Code: Select all

>	WorldServer.exe!CheckBytes(unsigned char * pb, unsigned char bCheck, unsigned int nSize) Line 1696	C++
 	WorldServer.exe!_free_dbg_nolock(void * pUserData, int nBlockUse) Line 1300	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_store_result@4()	Unknown
 	WorldServer.exe!Database::Select(DatabaseResult * result, const char * fmt, ...) Line 169	C++
 	WorldServer.exe!WorldDatabase::LoadNPCs(unsigned int chunk_id, ChunkServer & chunk) Line 974	C++
 	WorldServer.exe!WorldDatabase::LoadUnrealData(unsigned int chunk_id, ChunkServer & chunk) Line 950	C++
 	WorldServer.exe!ChunkServer::LoadChunkSpawns() Line 926	C++
 	WorldServer.exe!ChunkServer::Start() Line 256	C++
 	WorldServer.exe!Net::SendClientChunkInfo(std::shared_ptr<Client> & client, int coord_x, int coord_y) Line 568	C++
 	WorldServer.exe!ChunkServer::HandleZoneRequest(std::shared_ptr<Client> & client, PacketStruct & packet_struct) Line 916	C++
 	WorldServer.exe!ChunkServer::ProcessPackets() Line 309	C++
 	WorldServer.exe!ChunkPacketThread(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!7609338a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77189f72()	Unknown
 	ntdll.dll!77189f45()	Unknown

I was hauling ass from Vol Tuniel to Wardship across a few short corners, when I hit Wardship from Dahknarg, world exploded.

[quote]19:12:56.901 I Chunk Received zone request!
19:12:56.901 I Chunk New zone (-22, 25)
19:12:56.901 D Rules Rule: R_Chunk:ProcessThreadSleepMS, Value: 50
19:12:56.901 D Rules Rule: R_Chunk:RemoveSpawnDistance, Value: 17000
19:12:56.917 D Rules Rule: R_Chunk:MaxSendSpawnDistance, Value: 8500
19:12:56.917 D Rules Rule: R_Chunk:HearChatDistance, Value: 8500
19:12:56.917 D Chunk Starting chunk 'Dahknarg' (180)
19:12:56.917 D Rules Rule: R_Dev:LoadNPCData, Value: 1
19:12:56.917 D Unreal Loading Unreal data from the database.
19:12:56.917 D NPC Loading NPCs
19:12:57.244 D NPC Loaded 160 NPCs.
19:12:57.322 D Object Loaded 11 Objects.
19:12:57.338 D Music Loaded 1 Music files.
19:12:57.338 D Sound Loaded 1 Sounds.
19:12:57.338 D Unreal Loaded 1 Movers.
19:12:57.400 19:12:57.400 I I UDP UDP Client from 68.98.218.5:27018 set to disconnect : Application
New client connected from 68.98.218.5:42508
19:12:57.400 I UDP Received session request from 68.98.218.5:42508 with connection ID 1737593710
19:12:57.509 I Chunk New Session: Account ID: 1 Session ID: 'erngppv69rmue3mktt7h243u51'
19:12:57.619 D Chunk control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
19:12:57.728 D Chunk control_text='LOGIN'
19:12:58.430 I UDP Client from 68.98.218.5:27018 has been removed.
19:12:58.477 I Chunk Starting chunk shutdown timer for Thelaseen.
19:12:58.508 D Chunk control_text='JOIN'
19:13:08.866 I Chunk Received zone request!
19:13:08.866 I Chunk New zone (-20, 12)
19:13:08.866 D Rules Rule: R_Chunk:ProcessThreadSleepMS, Value: 50
19:13:08.866 D Rules Rule: R_Chunk:RemoveSpawnDistance, Value: 17000
19:13:08.882 19:13:08.882 D I Rules Chunk Rule: R_Chunk:MaxSendSpawnDistance, Value: 8500
Received zone request!
19:13:08.882 19:13:08.882 D I Rules Chunk Rule: R_Chunk:HearChatDistance, Value: 8500
New zone (-23, 25)
19:13:08.882 D Chunk Starting chunk 'Wildgrowth Forest' (9)
19:13:08.882 D 19:13:08.882 Rules D Rule: R_Chunk:ProcessThreadSleepMS, Value: 50
Rules Rule: R_Dev:LoadNPCData, Value: 1
19:13:08.882 D 19:13:08.882 Rules D Rule: R_Chunk:RemoveSpawnDistance, Value: 17000
Unreal Loading Unreal data from the database.
19:13:08.898 D 19:13:08.898 Rules D Rule: R_Chunk:MaxSendSpawnDistance, Value: 8500
NPC Loading NPCs
19:13:08.898 D Rules Rule: R_Chunk:HearChatDistance, Value: 8500
19:13:08.898 D Chunk Starting chunk 'Wardship of the Sleeping Moon' (173)
19:13:08.898 D Rules Rule: R_Dev:LoadNPCData, Value: 1
19:13:08.898 D Unreal Loading Unreal data from the database.
19:13:08.898 D NPC Loading NPCs
[/quote]