World Crash in Client::GetCharacter()

[Lokked]

Devs, for testing's sake, we can reproduce this fairly reliably by closing the client during the loading screen while rifting, then restarting the client again and immediately logging in.

I had a way to reproduce it 100% with breakpoints and letting the client timeout, but I'll have to verify at home exactly what I was doing. It was during the work on UnrealChannels, so perhaps putting a breakpoint in CloseAllChannels function until the client closes did it.

[Volt]

The log files are gold.
I will add logging to when camping is triggered and when camping is finalized. That will be helpful when reading the logs.

Sharing two findings. I don't have an analysis of yet.

2014-10-10_vgemu_world_748.log:

Code: Select all

1002 13:55:14.736 D Char     Saved character 'Zippyzee Doodah' (74) data.
1003 13:55:14.736 I UDP      Client from NN.NNN.NNN.NN:61943 set to disconnect : Application
1004 13:55:14.783 D Account  Client Created: 5
1005 13:55:14.783 I UDP      New client connected from NN.NNN.NNN.NN:61943
1006 13:55:15.173 E Unreal   Could not find unreal channel list for account id 0!

Disconnecting and connecting the same port. This is not good.
Looks like a timing issue in the server. While Zippyzee's chunk connection is being closed down, the UDP server gets a new packet from the client, notices that the chunk connection is not in the clients lists and decides that we have a new connection and opens it up.
Log lines 1002 and 1006 is probably Net::CheckPendingCharacterDeletions() line 685 and line 689.
Log line 1005 is probably UDPServer::HandleRead() line 332.
Saving the character to the database in Net::CheckPendingCharacterDeletions looks like it would take the time that could make the difference if we trigger the timing issue or not. On the other hand we should rather have a solution that is robust to delays.

EDIT: Scrap this "finding", this is from the character select screen and is correct behavior.
2014-10-12_vgemu_world_3836.log:

Code: Select all

05:47:00.612 D Char     Loading character 'Source one' (305) for account_id: 189
05:47:00.628 D Char     Loading character 'ssource' (486) for account_id: 189
05:47:00.628 D Net      Sending char data for 'Source', New Telon
05:47:00.628 D Net      Sending char data for 'ssource', New Telon

One account logs in and seems to get two character objects created. This is not good.[/strike]
Was also not any JOIN for this one.