Skip to content

Instantly share code, notes, and snippets.

@BenDol
Last active June 20, 2019 01:36
Show Gist options
  • Save BenDol/da5318e1d41b0a1473f9e5e9b5033bfc to your computer and use it in GitHub Desktop.
Save BenDol/da5318e1d41b0a1473f9e5e9b5033bfc to your computer and use it in GitHub Desktop.
Okay so I've been researching this movement flickering issue. I compiled some client network sniffs of the movement data and flattened them out. Each time I observed a flicker used a macro that `/say here` so I could see if there are any strange position data sent to the client from our core. Not sure if there is anything strange happening.
Flicker Movement Client Network Data:
* -flicker = the moment I observed a flicker in game
--[1]----------------------
X: -602.9882 Y: -4252.852 Z: 38.95627 O: 6.067197 (MSG_MOVE_SET_FACING, Time: 225716)
X: -602.6502 Y: -4252.942 Z: 38.95627 O: 5.925826 (MSG_MOVE_SET_FACING, Time: 225766) (50ms)
X: -602.4381 Y: -4253.033 Z: 38.95627 O: 5.772674 (MSG_MOVE_SET_FACING, Time: 225799) (33ms)
X: -602.2281 Y: -4253.159 Z: 38.95627 O: 5.654864 (MSG_MOVE_SET_FACING, Time: 225834) (35ms)
X: -601.9659 Y: -4253.368 Z: 38.95627 O: 5.525274 (MSG_MOVE_SET_FACING, Time: 225882) (500ms)
X: -599.5956 Y: -4255.943 Z: 38.95627 O: 5.450661 (MSG_MOVE_HEARTBEAT, Time: 226382)┐(500ms)
>> flicker |
X: -597.2401 Y: -4258.532 Z: 38.95627 O: 5.450661 (MSG_MOVE_HEARTBEAT, Time: 226882)┘(500ms)
X: -594.8851 Y: -4261.122 Z: 38.95627 O: 5.442807 (MSG_MOVE_HEARTBEAT, Time: 227382) (500ms)
X: -594.8118 Y: -4261.215 Z: 38.95627 O: 5.238604 (MSG_MOVE_SET_FACING, Time: 227399) (17ms)
X: -594.752 Y: -4261.318 Z: 38.95627 O: 5.085452 (MSG_MOVE_SET_FACING, Time: 227416) (17ms)
X: -594.7112 Y: -4261.423 Z: 38.95627 O: 4.940153 (MSG_MOVE_SET_FACING, Time: 227432) (16ms)
--[2]----------------------
X: -607.4963 Y: -4258.504 Z: 38.95602 O: 2.536835 (MSG_MOVE_SET_FACING, Time: 231768)
X: -607.6604 Y: -4258.397 Z: 38.95602 O: 2.646791 (MSG_MOVE_SET_FACING, Time: 231796) (28ms)
X: -607.8738 Y: -4258.292 Z: 38.95602 O: 2.784236 (MSG_MOVE_SET_FACING, Time: 231830) (34ms)
X: -608.207 Y: -4258.186 Z: 38.95602 O: 2.902046 (MSG_MOVE_SET_FACING, Time: 231880) (50ms)
X: -608.6603 Y: -4258.099 Z: 38.95602 O: 3.03949 (MSG_MOVE_SET_FACING, Time: 231946) (66ms)
X: -609.1284 Y: -4258.074 Z: 38.95602 O: 3.153373 (MSG_MOVE_SET_FACING, Time: 232013)┐(67ms)
>> flicker |
X: -612.6124 Y: -4258.397 Z: 38.95602 O: 3.243694 (MSG_MOVE_HEARTBEAT, Time: 232513)┘(500ms)
X: -613.4184 Y: -4258.493 Z: 38.95602 O: 3.455752 (MSG_MOVE_SET_FACING, Time: 232629) (116ms)
X: -613.5316 Y: -4258.529 Z: 38.95602 O: 3.628539 (MSG_MOVE_SET_FACING, Time: 232646) (17ms)
X: -613.4184 Y: -4258.493 Z: 38.95602 O: 3.455752 (MSG_MOVE_SET_FACING, Time: 232663) (17ms)
X: -613.5316 Y: -4258.529 Z: 38.95602 O: 3.628539 (MSG_MOVE_SET_FACING, Time: 232680) (17ms)
--[3]----------------------
X: -602.4247 Y: -4258.606 Z: 38.95483 O: 2.348337 (MSG_MOVE_SET_FACING, Time: 240563)
X: -602.5919 Y: -4258.447 Z: 38.95483 O: 2.454365 (MSG_MOVE_SET_FACING, Time: 240596) (33ms)
X: -603.4421 Y: -4257.796 Z: 38.95483 O: 2.564321 (MSG_MOVE_SET_FACING, Time: 240749) (153ms)
X: -603.828 Y: -4257.569 Z: 38.95483 O: 2.678204 (MSG_MOVE_SET_FACING, Time: 240813) (64ms)
X: -604.2617 Y: -4257.373 Z: 38.95483 O: 2.796014 (MSG_MOVE_SET_FACING, Time: 240881) (68ms)
X: -604.5886 Y: -4257.27 Z: 38.95483 O: 2.90597 (MSG_MOVE_SET_FACING, Time: 240930)┐(49ms)
>> flicker |
X: -605.97 Y: -4257.046 Z: 38.95483 O: 3.019852 (MSG_MOVE_SET_FACING, Time: 241130)┘(200ms)
X: -606.3185 Y: -4257.018 Z: 38.95483 O: 3.141589 (MSG_MOVE_SET_FACING, Time: 241180) (50ms)
X: -608.5349 Y: -4257.123 Z: 38.95483 O: 3.251545 (MSG_MOVE_SET_FACING, Time: 241497) (317ms)
X: -608.6462 Y: -4257.135 Z: 38.95483 O: 3.361501 (MSG_MOVE_SET_FACING, Time: 241513) (16ms)
X: -608.7692 Y: -4257.162 Z: 38.95483 O: 3.471457 (MSG_MOVE_SET_FACING, Time: 241531) (18ms)
--[4]----------------------
X: -610.7586 Y: -4254.211 Z: 38.95638 O: 5.352482 (MSG_MOVE_SET_FACING, Time: 247497)
X: -610.626 Y: -4254.4 Z: 38.95638 O: 5.242527 (MSG_MOVE_SET_FACING, Time: 247530) (33ms)
X: -610.515 Y: -4254.602 Z: 38.95638 O: 5.124717 (MSG_MOVE_SET_FACING, Time: 247563) (33ms)
X: -610.4293 Y: -4254.816 Z: 38.95638 O: 5.010835 (MSG_MOVE_SET_FACING, Time: 247596) (33ms)
X: -609.4766 Y: -4258.184 Z: 38.95638 O: 4.987273 (MSG_MOVE_HEARTBEAT, Time: 248096) (500ms)
X: -608.5266 Y: -4261.553 Z: 38.95638 O: 4.987273 (MSG_MOVE_HEARTBEAT, Time: 248596)┐(500ms)
>> flicker |
X: -607.5766 Y: -4264.921 Z: 38.95638 O: 4.987273 (MSG_MOVE_HEARTBEAT, Time: 249096)┘(500ms)
X: -607.4672 Y: -4265.261 Z: 38.95638 O: 5.215038 (MSG_MOVE_SET_FACING, Time: 249147) (51ms)
X: -607.4099 Y: -4265.365 Z: 38.95638 O: 5.391753 (MSG_MOVE_SET_FACING, Time: 249164) (17ms)
X: -607.3395 Y: -4265.452 Z: 38.95638 O: 5.576321 (MSG_MOVE_SET_FACING, Time: 249180) (16ms)
X: -607.249 Y: -4265.529 Z: 38.95638 O: 5.768744 (MSG_MOVE_SET_FACING, Time: 249197) (17ms)
--[5]----------------------
X: -593.2695 Y: -4257.595 Z: 38.95638 O: 1.727869 (MSG_MOVE_SET_FACING, Time: 251563)
X: -593.3164 Y: -4257.362 Z: 38.95638 O: 1.89673 (MSG_MOVE_SET_FACING, Time: 251597) (34ms)
X: -593.3987 Y: -4257.146 Z: 38.95638 O: 2.045956 (MSG_MOVE_SET_FACING, Time: 251630) (33ms)
X: -593.5101 Y: -4256.944 Z: 38.95638 O: 2.148057 (MSG_MOVE_SET_FACING, Time: 251663) (33ms)
X: -593.714 Y: -4256.66 Z: 38.95638 O: 2.277648 (MSG_MOVE_SET_FACING, Time: 251713) (50ms)
X: -593.9568 Y: -4256.399 Z: 38.95638 O: 2.395458 (MSG_MOVE_SET_FACING, Time: 251764)┐(51ms)
>> flicker |
X: -596.5666 Y: -4254.251 Z: 38.95638 O: 2.195181 (MSG_MOVE_SET_FACING, Time: 252247)┘(483ms)
X: -596.6321 Y: -4254.16 Z: 38.95638 O: 2.042029 (MSG_MOVE_SET_FACING, Time: 252263) (16ms)
X: -596.6861 Y: -4254.054 Z: 38.95638 O: 1.884949 (MSG_MOVE_SET_FACING, Time: 252280) (17ms)
X: -596.7228 Y: -4253.941 Z: 38.95638 O: 1.767139 (MSG_MOVE_SET_FACING, Time: 252297) (17ms)
X: -596.759 Y: -4253.706 Z: 38.95638 O: 1.53152 (MSG_MOVE_SET_FACING, Time: 252331) (34ms)
--[6]----------------------
X: -610.38 Y: -4263.606 Z: 38.9547 O: 5.537049 (MSG_MOVE_SET_FACING, Time: 260551)
X: -610.22 Y: -4263.743 Z: 38.9547 O: 5.639151 (MSG_MOVE_SET_FACING, Time: 260581) (30ms)
X: -609.1803 Y: -4264.491 Z: 38.9547 O: 5.808011 (MSG_MOVE_SET_FACING, Time: 260764) (183ms)
X: -608.9709 Y: -4264.588 Z: 38.9547 O: 5.957237 (MSG_MOVE_SET_FACING, Time: 260797) (33ms)
X: -608.6345 Y: -4264.684 Z: 38.9547 O: 6.075047 (MSG_MOVE_SET_FACING, Time: 260847) (50ms)
X: -608.1726 Y: -4264.763 Z: 38.9547 O: 6.185002 (MSG_MOVE_SET_FACING, Time: 260914)┐(67ms)
>> flicker |
X: -604.6837 Y: -4265.04 Z: 38.9547 O: 6.204637 (MSG_MOVE_HEARTBEAT, Time: 261386)┘(472ms)
X: -603.7559 Y: -4265.118 Z: 38.9547 O: 6.047557 (MSG_MOVE_SET_FACING, Time: 261519) (133ms)
X: -603.6402 Y: -4265.146 Z: 38.9547 O: 5.878697 (MSG_MOVE_SET_FACING, Time: 261536) (17ms)
X: -603.5308 Y: -4265.192 Z: 38.9547 O: 5.709836 (MSG_MOVE_SET_FACING, Time: 261553) (17ms)
X: -603.4367 Y: -4265.253 Z: 38.9547 O: 5.572392 (MSG_MOVE_SET_FACING, Time: 261569) (16ms)
@BenDol
Copy link
Author

BenDol commented Jun 16, 2019

Key Observations:

  • There are time spikes of around 200ms to 500ms when the "flicker" occurs.
  • Predominantly observed when moving the players orientation while moving forward (left <-> right, opcode: MSG_MOVE_SET_FACING).
  • Most of the flickers contain a jump in their X coordinate significantly larger than the previous trends, the same can be seen with the Y coordinate in some cases.

Footage:
flicker

General Notes:
2 minutes of running around shows flooding of MSG_MOVE_SET_FACING

--------starting metrics:-------
--------printing metrics:-------
 00000000000000DA: called 472 times
 [0] 0ms
 [1] 0ms
 [2] 0ms
 [3] 0ms
 [4] 0ms
 [5] 0ms

First movement packets show a high Time (probably our own movement):

ClientToServer: CMSG_TIME_SYNC_RESPONSE (0x0391) Length: 8 ConnIdx: 0 Time: 06/14/2019 18:41:56.000 Number: 8
Counter: 1
Ticks: 46150828

ClientToServer: MSG_MOVE_SET_FACING (0x00DA) Length: 29 ConnIdx: 0 Time: 06/14/2019 18:42:29.000 Number: 67
Movement Flags: 0 (None)
Extra Movement Flags: 0 (None)
Time: 46183195 << high
Position: X: -616.845 Y: -4253.15 Z: 38.933
Orientation: 6.271401
Fall Time: 0

ClientToServer: MSG_MOVE_SET_FACING (0x00DA) Length: 29 ConnIdx: 0 Time: 06/14/2019 18:42:29.000 Number: 68
Movement Flags: 0 (None)
Extra Movement Flags: 0 (None)
Time: 46183245 << high
Position: X: -616.845 Y: -4253.15 Z: 38.933
Orientation: 6.165372
Fall Time: 0

Then exhibiting movement from the other player the Time is a lot smaller:

ServerToClient: MSG_MOVE_FALL_LAND (0x00C9) Length: 31 ConnIdx: 0 Time: 06/14/2019 18:42:56.000 Number: 99
Guid: Full: 0x0000000F Type: Player Low: 15 Name: Rer
Movement Flags: 0 (None)
Extra Movement Flags: 0 (None)
Time: 167517 << lower
Position: X: -618.518 Y: -4251.67 Z: 38.718
Orientation: 0
Fall Time: 0

ServerToClient: SMSG_COMPRESSED_UPDATE_OBJECT (0x01F6) Length: 22 ConnIdx: 0 Time: 06/14/2019 18:42:56.000 Number: 100
Count: 1
Has Transport: false
[0] UpdateType: Values
[0] GUID: Full: 0x0000000F Type: Player Low: 15 Name: Rer

ServerToClient: MSG_MOVE_SET_FACING (0x00DA) Length: 31 ConnIdx: 0 Time: 06/14/2019 18:42:56.000 Number: 102
Guid: Full: 0x0000000F Type: Player Low: 15 Name: Rer
Movement Flags: 0 (None)
Extra Movement Flags: 0 (None)
Time: 168432 << lower
Position: X: -618.518 Y: -4251.67 Z: 38.718
Orientation: 6.275331
Fall Time: 0

ServerToClient: MSG_MOVE_START_STRAFE_RIGHT (0x00B9) Length: 31 ConnIdx: 0 Time: 06/14/2019 18:42:56.000 Number: 103
Guid: Full: 0x0000000F Type: Player Low: 15 Name: Rer
Movement Flags: 8 (StrafeRight)
Extra Movement Flags: 0 (None)
Time: 168449 << lower
Position: X: -618.518 Y: -4251.67 Z: 38.718
Orientation: 6.228208
Fall Time: 0

@BenDol
Copy link
Author

BenDol commented Jun 17, 2019

Further Tests:
I tested to see if the MSG_MOVE_SET_FACING packets observed on the client match the number of calls to the server, checking if they match 1:1 and they do. 100 packets from the client result in 100 calls to and from the server. (can post results later)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment