View Issue Details

IDProjectCategoryView StatusLast Update
0004427Spring engineGeneralpublic2014-06-30 13:39
ReporterAnarchid Assigned Tocleanrock  
PrioritynormalSeverityminorReproducibilitysometimes
Status resolvedResolutionreopened 
Product Version97.0.1+git 
Target Version98.0 
Summary0004427: Jerky unit animations when rejoining a game on 97.0.1-19
DescriptionRejoining a game causes all animations to appear as if at significantly reduced FPS. This appears to everything, most notably metal extractors and windmills make it easily observable.

It applies to both players and spectators. There are sporadic reports on when it does not happen. All cases where it happened thus far were on Linux.

Amount of units on map doesn't seem to matter, the issue was observed with as few as 40.
Steps To Reproduce1) Find an unready game to spectate.
2) Wait for it to start.
3) Observe nice and smooth animations.
4) Quit and rejoin the same game.
5) Windgens, metal extractrs, and everything animate jerkily. Projectiles and unit positions are smooth. Fps is normal.
Additional InformationThus far only tested with ZK, but nature of bug seems to preclude effect of luarules or luaui.

Only seems to affect the actually rejoining players: both players and spectators who did not rejoin reported smooth animations with no disruption.

It was not tested whether this affects players catching-up without rejoin (i.e, after lagout).

Replay with demonstration available at http://zero-k.info/Battles/Detail/267494
TagsNo tags attached.
Attached Files
infolog_traces.txt (Attachment missing)
Checked infolog.txt for Errors

Activities

Anarchid

2014-06-09 20:17

reporter   ~0013242

It seems i can't modify the report, but engine version mentioned is not perfectly correct, game is on 97.0.1-18-gf1dd749.

Anarchid

2014-06-09 21:03

reporter   ~0013243

Update - does not occur only on linux.

Anarchid

2014-06-09 21:14

reporter   ~0013244

Another update - also happens for catch-up without rejoining.

Anarchid

2014-06-10 00:19

reporter   ~0013245

Additionally, it seems that alternating /fullscreen seems to occasionally restore the normal animation behavior.

Kloot

2014-06-10 02:19

developer   ~0013246

Last edited: 2014-06-10 02:19

Since piece animations are uninterpolated, the only? explanation for this would be a non-steady supply of simframes.

If you log the time in millisecs between consecutive frames after rejoining (over a period of 10 seconds or so), what sort of values do you see?

Google_Frog

2014-06-10 12:09

reporter   ~0013249

I have added a widget to log frame gaps. https://zero-k.googlecode.com/svn/trunk/mods/zk/LuaUI/Widgets/dbg_frame_gap_logger.lua

Anarchid

2014-06-10 13:04

reporter   ~0013254

infolog with above widget from a rejoining player:
http://pastebin.com/cZZbi63Q

Rejoin is finished at line 1112 [f=0030899] Sortale ENABLE TTS, magnitude of gaps seems to remain as it was during fast-forward.

The widget doesn't seem to log non-gappy frames.

Google_Frog

2014-06-10 13:43

reporter   ~0013255

It only mentions frame gaps of 100ms or more. Every frame not mentioned is a non-gappy frame.

Kloot

2014-06-10 14:36

developer   ~0013256

Last edited: 2014-06-10 14:40

"magnitude of gaps seems to remain as it was during fast-forward"

That's in line with what I expected.

It means the client catches up too close to the server (even though I added code to prevent this when fixing 3845 / 4171) and doesn't leave enough buffer room to smoothen out network bumps.

The_Yak

2014-06-11 21:42

reporter   ~0013269

I can reproduce this consistently on ZK and latest engine builds. Is more information required?

Kloot

2014-06-12 02:12

developer   ~0013271

no, just more time

cleanrock

2014-06-15 09:17

reporter   ~0013283

Perhaps caused by change to
const unsigned int numQueuedFrames = GetNumQueuedSimFrameMessages(-1u);
which cause lastNumQueuedSimFrames to get much bigger now and since it is only reduced every second will make consumeSpeedMult high for a long time:
lastNumQueuedSimFrames = mix(lastNumQueuedSimFrames * 1.0f, numQueuedFrames * 1.0f, 0.1f);
consumeSpeedMult = GAME_SPEED * gs->speedFactor + lastNumQueuedSimFrames - (2 * gs->speedFactor);

cleanrock

2014-06-23 18:01

reporter   ~0013326

Last edited: 2014-06-23 18:05

I investigated more and this unit jitter can still happen.
msgProcTimeLeft goes very high when GetNumQueuedSimFrameMessages(-1u) is used and decrease very slow when catched up.
https://github.com/spring/spring/commit/05e4f29 seem to reduce risk of msgProcTimeLeft going insane but i think we need to fix this better.
Attached a log with some extra debug traces, catch up happens around line 500.
Also, using UseNetMessageSmoothingBuffer=0 is bad atm, u will most probably get unit jitter after catching up.

silentwings

2014-06-24 00:35

reporter   ~0013340

Last edited: 2014-06-29 13:56

Unit movement, just in a single player game of BA 8.00, after doing /give all and giving all a single move command, is VERY (i.e. unplayably) jerky for me in 97.0.1-23, also -75 and -94, which is all I've tested so far.

97.0.1-20 is smooth for me, just as 96.0 is.

cleanrock suggested changing WTC (-1 or 0) and WTST values (0 or 5) but this seems to have no effect.

Let me know if you can't reproduce this.

cleanrock

2014-06-27 12:09

reporter   ~0013369

Please test 97.0.1-125-ga0ba15f to see if unit jitter is fixed in multi-player games.
To test locally you can launch a AIvsAI game and connect with an local spec client:
BypassScriptPasswordCheck = 1
spring(.exe) spring://spec1@localhost
(use spec2 if you want to reconnect your spec client)

It will most probably not fix single player jitter since it uses its own net reading strategy.

Issue History

Date Modified Username Field Change
2014-06-09 20:14 Anarchid New Issue
2014-06-09 20:17 Anarchid Note Added: 0013242
2014-06-09 21:03 Anarchid Note Added: 0013243
2014-06-09 21:14 Anarchid Note Added: 0013244
2014-06-10 00:19 Anarchid Note Added: 0013245
2014-06-10 02:19 Kloot Note Added: 0013246
2014-06-10 02:19 Kloot Note Edited: 0013246
2014-06-10 12:09 Google_Frog Note Added: 0013249
2014-06-10 13:04 Anarchid Note Added: 0013254
2014-06-10 13:43 Google_Frog Note Added: 0013255
2014-06-10 14:36 Kloot Note Added: 0013256
2014-06-10 14:40 Kloot Note Edited: 0013256
2014-06-11 21:42 The_Yak Note Added: 0013269
2014-06-12 02:08 abma Target Version => 98.0
2014-06-12 02:12 Kloot Note Added: 0013271
2014-06-15 09:17 cleanrock Note Added: 0013283
2014-06-22 13:47 cleanrock Changeset attached => spring develop 05e4f29f
2014-06-22 13:47 cleanrock Assigned To => cleanrock
2014-06-22 13:47 cleanrock Status new => resolved
2014-06-22 13:47 cleanrock Resolution open => fixed
2014-06-23 18:01 cleanrock Assigned To cleanrock =>
2014-06-23 18:01 cleanrock Note Added: 0013326
2014-06-23 18:01 cleanrock Status resolved => feedback
2014-06-23 18:01 cleanrock Resolution fixed => reopened
2014-06-23 18:01 cleanrock Status feedback => new
2014-06-23 18:03 cleanrock File Added: infolog_traces.txt
2014-06-23 18:04 cleanrock Note Edited: 0013326
2014-06-23 18:05 cleanrock Note Edited: 0013326
2014-06-24 00:35 silentwings Note Added: 0013340
2014-06-24 00:36 silentwings Note Edited: 0013340
2014-06-24 01:42 silentwings Note Edited: 0013340
2014-06-24 01:45 silentwings Note Edited: 0013340
2014-06-27 12:09 cleanrock Note Added: 0013369
2014-06-29 13:56 silentwings Note Edited: 0013340
2014-06-30 13:39 cleanrock Changeset attached => spring develop 73f1b825
2014-06-30 13:39 cleanrock Assigned To => cleanrock
2014-06-30 13:39 cleanrock Status new => resolved