Page 1 of 1

Random Disconnects

Posted: Sat Aug 16, 2014 2:29 pm
by John Adams
While troubleshooting the other issues, something odd happened when I left everything and walked away for a bit. I had 3 characters logged in, each in different chunks. 2 of those characters crossed multiple chunk lines moving around the world. One of them left Bordinar's Cleft, then turned around and went back in. That's when I walked away.

Sometime in the next 12 minutes (oddly), everyone got booted. Here's the log from the point my 2nd toon left Bordinar's Cleft to 3R then went back:

Enter 3R
[quote]13:51:22.812 I Chunk Received zone request!
13:51:22.813 I Chunk New zone (-27, 26)
13:51:22.816 D Rules Rule: R_Chunk:ProcessThreadSleepMS, Value: 50
13:51:22.817 D Rules Rule: R_Chunk:RemoveSpawnDistance, Value: 17000
13:51:22.818 D Rules Rule: R_Chunk:MaxSendSpawnDistance, Value: 8500
13:51:22.819 D Rules Rule: R_Chunk:HearChatDistance, Value: 8500
13:51:22.820 D Chunk Starting chunk 'Three Rivers' (143)
13:51:22.821 D Rules Rule: R_Dev:LoadNPCData, Value: 1
13:51:22.821 D Unreal Loading Unreal data from the database.
13:51:22.822 D NPC Loading NPCs
13:51:23.080 D NPC Loaded 303 NPCs.
13:51:23.157 D Object Loaded 54 Objects.
13:51:23.165 D Music Loaded 1 Music files.
13:51:23.168 D Sound Loaded 1 Sounds.
13:51:23.169 D Unreal Loaded 1 Movers.
13:51:23.247 I UDP Client from 192.168.1.108:50419 set to disconnect : Application
13:51:23.253 I UDP New client connected from 192.168.1.108:49786
13:51:23.253 I UDP Received session request from 192.168.1.108:49786 with connection ID 1497590908
13:51:23.335 I Chunk New Session: Account ID: 2 Session ID: '2'
13:51:23.406 D Chunk control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
13:51:23.467 D Chunk control_text='LOGIN'
13:51:23.530 D Chunk control_text='JOIN'
13:51:23.539 D Rules Rule: R_Player:DefaultMovementSpeed, Value: 750.0
13:51:24.473 I UDP Client from 192.168.1.108:50419 has been removed.
13:51:24.514 I Chunk Starting chunk shutdown timer for Bordinar's Cleft.[/quote]

Back to BC
[quote]13:52:10.087 I Chunk Received zone request!
13:52:10.088 I Chunk New zone (-28, 26)
13:52:10.093 I UDP Client from 192.168.1.108:49786 set to disconnect : Application (leaving 3R)
13:52:10.098 I UDP New client connected from 192.168.1.108:49795
13:52:10.098 I UDP Received session request from 192.168.1.108:49795 with connection ID 137414369
13:52:10.123 I Chunk Chunk shutdown cancelled for Bordinar's Cleft.
13:52:10.179 I Chunk New Session: Account ID: 2 Session ID: '2'
13:52:10.250 D Chunk control_text='HELLO REVISION=0 MINVER=3151 VER=3186'
13:52:10.311 D Chunk control_text='LOGIN'
13:52:10.369 D Chunk control_text='JOIN'
13:52:10.374 D Rules Rule: R_Player:DefaultMovementSpeed, Value: 750.0
13:52:11.820 I UDP Client from 192.168.1.108:49786 has been removed. (leaving 3R)
13:52:11.847 I Chunk Starting chunk shutdown timer for Three Rivers.[/quote]

...5 minutes later... (expected)
[quote]13:57:11.881 I Chunk Shutdown timer expired. Shutting down Three Rivers.[/quote]

Then, 7 more minutes and boom, die die die.
[quote]14:04:01.969 I UDP Client from 192.168.1.101:56539 set to disconnect : Timeout
14:04:03.969 I UDP Client from 192.168.1.101:56539 has been removed.
14:05:03.283 I UDP Client from 192.168.1.101:56540 set to disconnect : Timeout
14:05:03.969 I UDP Client from 192.168.1.100:59658 set to disconnect : Timeout
14:05:04.283 I UDP Client from 192.168.1.101:56540 has been removed.
14:05:04.309 I Chunk Starting chunk shutdown timer for Isle of Dawn.
14:05:04.969 I UDP Client from 192.168.1.100:59658 has been removed.
14:05:43.938 I UDP Client from 192.168.1.100:56697 set to disconnect : Timeout
14:05:45.938 I UDP Client from 192.168.1.100:56697 has been removed.
14:05:45.977 I Chunk Starting chunk shutdown timer for Ruins of Trengal Keep.
14:10:04.338 I Chunk Shutdown timer expired. Shutting down Isle of Dawn. (client #3)
14:10:46.016 I Chunk Shutdown timer expired. Shutting down Ruins of Trengal Keep. (client #1)[/quote]
Clearly, the 192.168.1.108 (client #2) is at fault here, because notice nothing about it disconnecting from the re-entered Bordinar's Cleft, nor BC itself ever shutting down was mentioned. Almost like BC shut down/crashed quietly (no logging) and tore everyone else down.

Maybe try leaving a chunk, turning around and heading right back in may reproduce this bug.


Server never crashed, no errors, just everyone online got booted. This is with current SVN (614).

Re: Random Disconnects

Posted: Sat Aug 16, 2014 3:05 pm
by Lokked
Also, you mentioned you had 2 other clients connected, but they are each using 2 UDP ports (or at least, they disconnect from 2 ports) and had been sitting around not changing chunks. Is this normal to keep 2 ports per client open?

Re: Random Disconnects

Posted: Sat Aug 16, 2014 3:18 pm
by John Adams
At present, it is. One to the WorldServer, one to the ChunkServer. I am unclear if this is a limitation with the client(?) and how it manages connections, or if it's just a weird design that never got the attention it deserved.

If you do the math, 100 players in 100 chunks (200 ports), moving around with 5 minute timers to shut down, leaves a lot of open ports to the world server. I don't think that's right, but may be what we're stuck with. Other emu's don't do it this way (that I'm aware of) so I'm hopeful.


[quote="John Adams"]Maybe try leaving a chunk, turning around and heading right back in may reproduce this bug.[/quote]
Btw, just like my day job and everything else, I performed the exact same steps as above, and the connections did not disconnect this time. I am 0 for 2 today.