Disconnections and multiple-minute lag... about ready to pack it in

[mongol]

I'm not sure how many others out there are having the same experience, but I'm getting disconnected or (very rarely) experience several minutes of "stuck" then suddenly things come to life.. about every 1 to 5 minutes of game play.

The overwhelming majority of the time it is when speaking to an NPC..

I think I've missed most of the dialogue of the game.

Is it me, or are there countless people out there suffering the same plight?

Internet connection is solid as... d3debug is interesting, here is an example where the connection "paused" for 2 minutes 15 seconds...

012.06.02 12:19:23.980392000   STARTING NETWORK CLIENT GAME
2012.06.02 12:19:24.564803000   Setting depth texture, fmt = 36
2012.06.02 12:19:24.564973000   PostFXGfxInit() success
2012.06.02 12:19:24.565200000   SubObjectGfxInit() 1
2012.06.02 12:19:24.588465000   Connecting to 12.130.247.24:1119
2012.06.02 12:19:24.589192000   >>> Munter BnetParty::CloseStatusChange_SetPrivacyLevelCallback code=0  old=CLOSED(1) new=CALLTOARMS_MUTUALFRIENDS(4) reason=CREATING_GAME(0)
2012.06.02 12:19:24.833970000   -----------------------------------------------------------------
2012.06.02 12:19:24.834148000   Server Version Information:
2012.06.02 12:19:24.834290000   -----------------------------------------------------------------
2012.06.02 12:19:24.834431000   Server BuildVersion: 1.0.2.9933
2012.06.02 12:19:24.834568000   Server SNOPackHash: 0xC87E9051 (client hash = 0xC87E9051)
2012.06.02 12:19:24.839706000   Server ProtocolHash: 0x33CABB38 (client hash = 0x33CABB38)
2012.06.02 12:19:24.840005000   -----------------------------------------------------------------
2012.06.02 12:19:25.779760000   Initializing client world trOUT_TownAttack...
2012.06.02 12:19:25.866198000   Initializing client world trOUT_Town...
2012.06.02 12:19:27.97945000    de activate app 0 iconic 0
2012.06.02 12:19:33.428079000   ACTIVATE APP 1 iconic 0
2012.06.02 12:19:34.939801000   de activate app 0 iconic 0
2012.06.02 12:19:39.538294000   ACTIVATE APP 1 iconic 0
2012.06.02 12:19:39.784553000   de activate app 0 iconic 0
2012.06.02 12:19:41.198152000   ACTIVATE APP 1 iconic 0
2012.06.02 12:19:52.591191000   de activate app 0 iconic 0
2012.06.02 12:19:52.977134000   ACTIVATE APP 1 iconic 0
2012.06.02 12:19:53.94002000    de activate app 0 iconic 0
2012.06.02 12:19:53.969838000   ACTIVATE APP 1 iconic 0
2012.06.02 12:20:13.390366000   de activate app 0 iconic 0
2012.06.02 12:20:14.181430000   ACTIVATE APP 1 iconic 0
2012.06.02 12:20:14.273877000   de activate app 0 iconic 0
2012.06.02 12:22:32.641069000   Received pong with old sequence!
2012.06.02 12:22:32.641187000   Received pong with old sequence!
2012.06.02 12:22:32.697594000   Received pong with old sequence!
2012.06.02 12:22:32.697871000   Received pong with old sequence!
2012.06.02 12:22:32.698082000   Received pong with old sequence!
2012.06.02 12:22:32.698154000   Received pong with old sequence!
2012.06.02 12:22:32.698241000   Received pong with old sequence!
2012.06.02 12:22:32.698394000   Received pong with old sequence!
2012.06.02 12:22:32.738748000   Received pong with old sequence!
2012.06.02 12:22:32.738910000   Received pong with old sequence!
2012.06.02 12:22:32.738988000   Received pong with old sequence!
2012.06.02 12:22:32.739056000   Received pong with old sequence!
2012.06.02 12:22:32.739128000   Received pong with old sequence!
2012.06.02 12:22:32.739195000   Received pong with old sequence!
2012.06.02 12:22:32.739263000   Received pong with old sequence!
2012.06.02 12:22:32.819873000   Received pong with old sequence!
2012.06.02 12:22:32.820020000   Received pong with old sequence!
2012.06.02 12:22:32.820098000   Received pong with old sequence!
2012.06.02 12:22:32.820206000   Received pong with old sequence!
2012.06.02 12:22:32.820296000   Received pong with old sequence!
2012.06.02 12:22:32.820417000   Received pong with old sequence!
2012.06.02 12:22:32.820524000   Received pong with old sequence!
2012.06.02 12:22:32.820650000   Received pong with old sequence!
2012.06.02 12:22:39.181349000   ACTIVATE APP 1 iconic 0
2012.06.02 12:22:39.322998000   de activate app 0 iconic 0

[mongol]

This is a little beyond me, but this is what is happening at the packet level right when a big *** (multi-minute) lag spike / disconnect begins:

[Curik]

Wow, I thought they moved away from TCP/IP when they released StarCraft 2! Is that really the gameservers traffic and not the loginserver?

I also have these spikes but didn't go as far as looking in a packet sniffer. What I did notice however (to my despair) is that the issue probably lies with the client. I tried on my regular workstation and it doesn't lag on the same connection as my laptop - my laptop lags on several different connections (even up to 300 km apart) which made me understand it wasn't network related. And it's not stuttering or anything, no framerate lag there; just high ping.

What I did on my laptop (even though it has ~40 fps all the time) was to lower the settings and enable vsync. Now the biggest spikes are in the range of 5-10 seconds - which is still worthless but manageable for me. The fact that they use TCP/IP only highlights this, as what happens is probably that it's waiting for an old packet to arrive before processing the rest of the packet queue.

Somethings needs to be done with the client, that's for sure.

[mongol]

Wow, I thought they moved away from TCP/IP when they released StarCraft 2! Is that really the gameservers traffic and not the loginserver?

I also have these spikes but didn't go as far as looking in a packet sniffer. What I did notice however (to my despair) is that the issue probably lies with the client. I tried on my regular workstation and it doesn't lag on the same connection as my laptop - my laptop lags on several different connections (even up to 300 km apart) which made me understand it wasn't network related. And it's not stuttering or anything, no framerate lag there; just high ping.

What I did on my laptop (even though it has ~40 fps all the time) was to lower the settings and enable vsync. Now the biggest spikes are in the range of 5-10 seconds - which is still worthless but manageable for me. The fact that they use TCP/IP only highlights this, as what happens is probably that it's waiting for an old packet to arrive before processing the rest of the packet queue.

Somethings needs to be done with the client, that's for sure.

Yes I can confirm it is the gameserver traffic, basically because if I spam click to walk around I can see the packets in wireshark going back and forth. The really bizarre thing is that for each click, a packet goes out, and an ACK is received back... so the server side IS at least acknowledging the receipt of that packet at the (TCP) protocol layer... but is the app layer doing anything ? BIG SHRUG.

I'd also wonder like you do why this game's networking is developed using TCP... I do wonder if this game just suffers mightily from packet loss/resend type scenarios that cause either end (or both) significant delay waiting for resends on dropped/lost packets... combine that with a shakey connection point to point (and yes I can confirm there are zero errors on any port of any networking device up to my cable modem) and I guess that's why most internet games rely so heavily on UDP.

Lemme look at a few other things with wireshark to confirm there's no other UDP traffic involved...

[mongol]

Confirming... I see *nothing* over UDP.

Will show some screenshots/dumps later today when I have some time to properly organize things.

[mongol]

What the crap is this background?

[mongol]

Posted this on battle.net, might as well crosspost since some of you may not login:

Okay here's what I can show... I'm not an expert in interpreting this data, but one thing is for sure: It doesn't look pretty.

First, here is a chart (one second intervals) showing all communication between my computer and anything in the 12.130.0.0/16 network (i.e., everything Battlenet) all the way from login through to me entering a game, talking to Leah, getting massive lag, then disconnected, then exiting the game.


black bars: Num of packets per interval
red dots: Number of Duplicate ACKs
green dots: Number of TCP Retransmissions
blue dots: Number of TCP Fast Retransmissions





Here is the complete CSV dump from wireshark during this same period (save it and open in Excel):


http://pastebin.com/vfLsvXf3



Here is my D3Debug log during the same period, with additional timestamps written by me every 1 second -- this because I noticed the D3Debug timestamps drift quite significantly over time!


http://pastebin.com/F5M01trk



The only thing I'll add is that 17:11:55 is precisely when the "lag" started, and 17:14:39 is precisely when the client decides to give up and announce it has disconnected. This coincides with duplicate ACKs and TCP Retransmits.


Also, this is almost 100% reproducible by talking to Tyrael or Leah in town. Before someone decides to cite network performance issues at any point in the route, please consider why network performance would always manifest itself as a disconnect on the very same game interaction... and I might as well also note that the total amount of data transferred to and from during this entire login/start game/talk/lag/disconnect/exit session was a whopping:


356KB, in 1324 packets, over 172 seconds for the FRIGHTENING throughput of 2075 bytes per second... yeah... I can totally see how that would be causing network performance problems ... </sarcasm>



Someone way more knowledgeable in TCP/IP is going to need to interpret this...

[Curik]

Yeah that's what I figured too, it must be somewhere on the application layer if they're waiting for a packet to get resent - and while that happens the simulation is stalled. This is quite obvious when it catches up, everything replays so fast.

Have you tried lowering your settings? Just to test things out! It helped on my side, although it's no solution as I get 30+ fps anyway on higher settings and it should be sufficent. Maybe it's the networking thread deadlocking briefly or something, it must be on the application level.

Edit: And honestly, I think they'll solve this eventually. They probably won't mention and will just silent-patch it - maybe they'll even follow the example of SC2 and switch transparently to UDP - but I can't remember if they did that in the SC2 beta or afterwards... hopefully the latter.

Another edit: I do not get disconnected much though it happens, but not that often.

[mongol]

So get this...

I did some reading about NAT and found some commonly used settings that can interfere with TCP streams that are timing dependent... looked up in my current router's firmware whether or not it had these settings.. it did not. But... a recent version of the router's firmware (Linksys WRT54GS, btw) did.. So I upgraded the firmware ..

Without touching any setting on it from default, the random disconnects and lag goes away...

And was promptly replaced by yesterday's "maintenance" which causes the game to slow to a crawl over 5-10 minutes then "Removed from game"!!!

And today? A new patch... Cannot even retrieve hero list anymore...

This must be THE WORST game launch in history... a complete shambles. Every single thing they do replaces one set of issues for another, and to top it all off, their app layer comm protocol is insanely sensitive to NAT which is something that just about EVERYONE uses.

[swayzesghost]

Fail to see how you can blame this on Blizzard. Looks like it's a routing problem on your end.