MantisBT - Zandronum
View Issue Details
0001897Zandronum[All Projects] Bugpublic2014-07-24 00:372018-09-30 21:50
unknownna 
Torr Samaho 
urgentmajoralways
closedfixed 
Windows8.1
1.2 
3.03.0 
0001897: CPU-like lag when picking up items or when flag is taken/dropped/returned after a dozen map changes || Console memory issue
I've been playing a lot of CTF and survival lately and have noticed a distinct lag in CTF. After around a dozen map changes, the client starts to lag whenever players join the game, whenever flags are taken/dropped/returned and whenever picking up items. The lag that occurs whenever a flag is taken/dropped/returned and when picking up items is very frustrating to play with.

It is imperative that this issue is looked into is as it prevents you from predicting your own and others movement properly. Note that this isn't some sort of a client-side misprediction at all, it's just some strange CPU-like lag that "piles up" after map changes. It feels like a memory leak, but by looking at the Windows task manager I can see that the memory usage seems to stay the same.

Have a look at the demo in the link below. It starts at MAP01 so you're going to have to use the demo_skiptonextmap command a bit often to get to the later maps. I already notice the lag in MAP11 and MAP16, but it really shows in MAP18 and particularly in MAP21.
1. zandronum -file skulltag_actors_1-1-1.pk3 skulltag_data_126.pk3 veloctfx.wad odaflagx.pk3 skullspree4a.wad hudtimer_v3b.pk3 ctfcaptains_v1b.wad newtextcolours1_170.pk3 connectsound.wad -playdemo 2014.07.21_18.42.10_skulltag_actors_1-1-1pk3.skulltag_data_126pk3.veloctfx.odaflagxpk3.skullspree4a.hudtimer_v3bpk3.ctfcaptains_v1b.newtextcolours1_170pk3.connectsound.cld
2. demo_skiptonextmap to MAP16, MAP18 and MAP21

2014.07.21_18.42.10_skulltag_actors_1-1-1pk3.skulltag_data_126pk3.veloctfx.odaflagxpk3.skullspree4a.hudtimer_v3bpk3.ctfcaptains_v1b.newtextcolours1_170pk3.connectsound.cld
skulltag_actors_1-1-1.pk3
skulltag_data_126.pk3
veloctfx.wad
odaflagx.pk3
skullspree4a.wad
hudtimer_v3b.pk3
ctfcaptains_v1b.wad
newtextcolours1_170.pk3
connectsound.wad
I can always reproduce this issue on the Grandvoid and FUNCRUSHER servers simply by joining a game and playing around 6-10 maps. Every map after that will lag more and more. The only way to fix this is to quit and restart zandronum.exe, simply disconnecting and reconnecting doesn't fix the issue. And it seems that cl_ticsperupdate and cl_unlagged don't have any effect here. I also don't observe this behavior on ZDaemon servers.
No tags attached.
related to 0000463resolved  Ambient sounds pile up for incoming clients, after map changes and after reconnecting 
related to 0002269closed Torr Samaho Memory leak when running wad with large sectors 
Issue History
2014-07-24 00:37unknownnaNew Issue
2014-07-24 00:51unknownnaNote Added: 0010050
2014-07-24 00:56unknownnaRelationship addedrelated to 0000463
2015-06-06 17:40unknownnaNote Added: 0012551
2015-06-06 17:40unknownnaPriorityhigh => normal
2015-06-06 17:40unknownnaSteps to Reproduce Updatedbug_revision_view_page.php?rev_id=7269#r7269
2015-06-06 17:41unknownnaRelationship addedrelated to 0002269
2015-06-06 19:25unknownnaNote Edited: 0012551bug_revision_view_page.php?bugnote_id=12551#r7271
2015-06-17 05:23unknownnaNote Added: 0012745
2015-06-17 06:11unknownnaNote Edited: 0012745bug_revision_view_page.php?bugnote_id=12745#r7485
2015-06-17 14:29unknownnaNote Edited: 0012745bug_revision_view_page.php?bugnote_id=12745#r7492
2015-06-17 14:43unknownnaNote Edited: 0012745bug_revision_view_page.php?bugnote_id=12745#r7493
2015-07-12 01:32unknownnaNote Added: 0012859
2015-07-12 15:48unknownnaNote Added: 0012895
2015-07-12 15:51unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7609
2015-07-12 16:27unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7610
2015-07-13 06:34unknownnaNote Edited: 0012859bug_revision_view_page.php?bugnote_id=12859#r7627
2015-07-13 09:19unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7628
2015-07-13 09:23unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7629
2015-07-13 09:34unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7630
2015-07-13 09:38unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7631
2015-07-13 09:39unknownnaPrioritynormal => high
2015-07-13 09:39unknownnaStatusnew => confirmed
2015-07-13 09:39unknownnaSummaryCPU-like lag when picking up items or when flag is taken/dropped/returned after a dozen map changes in CTF => CPU-like lag when picking up items or when flag is taken/dropped/returned after a dozen map changes || Console memory issue
2015-07-13 09:43unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7632
2015-07-13 09:47unknownnaNote Edited: 0012895bug_revision_view_page.php?bugnote_id=12895#r7633
2015-07-13 09:53unknownnaNote Edited: 0012551bug_revision_view_page.php?bugnote_id=12551#r7634
2015-07-13 11:31unknownnaSteps to Reproduce Updatedbug_revision_view_page.php?rev_id=7635#r7635
2015-07-14 13:32unknownnaNote Added: 0012930
2015-07-14 13:33unknownnaStatusconfirmed => feedback
2015-07-14 14:27unknownnaNote Edited: 0012930bug_revision_view_page.php?bugnote_id=12930#r7674
2015-07-14 14:31unknownnaNote Edited: 0012930bug_revision_view_page.php?bugnote_id=12930#r7675
2015-07-14 16:29unknownnaNote Added: 0012931
2015-07-14 16:29unknownnaStatusfeedback => new
2015-07-14 16:29unknownnaStatusnew => acknowledged
2015-07-14 16:29unknownnaResolutionopen => waiting for zdoom
2015-07-14 16:31unknownnaNote Edited: 0012931bug_revision_view_page.php?bugnote_id=12931#r7677
2015-07-14 19:49unknownnaNote Added: 0012939
2015-07-16 01:42unknownnaNote Edited: 0012939bug_revision_view_page.php?bugnote_id=12939#r7695
2015-07-16 07:06unknownnaNote Edited: 0012939bug_revision_view_page.php?bugnote_id=12939#r7708
2015-07-16 07:06unknownnaNote Edited: 0012939bug_revision_view_page.php?bugnote_id=12939#r7709
2015-07-16 11:18unknownnaNote Edited: 0012939bug_revision_view_page.php?bugnote_id=12939#r7710
2015-07-16 11:21unknownnaPriorityhigh => urgent
2015-07-16 11:26unknownnaNote Edited: 0012939bug_revision_view_page.php?bugnote_id=12939#r7711
2015-07-16 12:29Edward-sanNote Added: 0012955
2015-07-16 12:50Edward-sanNote Edited: 0012955bug_revision_view_page.php?bugnote_id=12955#r7715
2015-07-16 12:51Edward-sanNote Edited: 0012955bug_revision_view_page.php?bugnote_id=12955#r7716
2015-07-16 16:10Edward-sanNote Edited: 0012955bug_revision_view_page.php?bugnote_id=12955#r7720
2015-07-16 19:14unknownnaNote Added: 0012956
2015-07-16 19:26unknownnaNote Edited: 0012956bug_revision_view_page.php?bugnote_id=12956#r7722
2015-07-16 19:58unknownnaNote Edited: 0012956bug_revision_view_page.php?bugnote_id=12956#r7723
2015-07-17 12:33unknownnaAssigned To => Edward-san
2015-07-17 12:33unknownnaStatusacknowledged => needs review
2015-07-20 13:59unknownnaNote View State: 0012931: private
2015-07-21 12:00unknownnaTarget Version => 2.2
2015-08-10 09:26unknownnaNote View State: 0012931: public
2015-12-01 12:26Edward-sanAssigned ToEdward-san =>
2016-07-02 11:20Torr SamahoNote Added: 0015165
2016-07-02 11:20Torr SamahoTarget Version2.2 => 3.0
2016-07-02 11:21Torr SamahoAssigned To => Torr Samaho
2016-07-02 11:21Torr SamahoStatusneeds review => needs testing
2016-07-02 15:39WaTaKiDNote Added: 0015175
2016-10-04 15:12unknownnaNote Added: 0015754
2017-01-30 01:11Ru5tK1ngNote Added: 0016723
2017-01-30 01:11Ru5tK1ngStatusneeds testing => resolved
2017-01-30 01:11Ru5tK1ngResolutionwaiting for zdoom => fixed
2017-01-30 01:11Ru5tK1ngFixed in Version => 3.0
2018-09-30 21:50Blzut3Statusresolved => closed

Notes
(0010050)
unknownna   
2014-07-24 00:51   
I also only use the software renderer.
(0012551)
unknownna   
2015-06-06 17:40   
(edited on: 2015-07-13 09:53)
I still notice this behavior in 2.0. It seems to be dependent on how many players there are per map. From what I've observed, if each successive map contains at least around 4 players per team, this undefined lag accumulates after each map. I only managed to work around this by forcing my laptop to run at 100% CPU at all times when playing CTF.

I also notice this issue on DM servers. For some reason it doesn't seem to happen on survival servers.

Edit:

And even setting the CPU to run at 100% at all times didn't fix the issue, it just made it take more map changes for the issue to appear.

(0012745)
unknownna   
2015-06-17 05:23   
(edited on: 2015-06-17 14:43)
ZDaemon still seems to remain 100% smooth compared to Zandronum after a dozen map changes. I'm beginning to believe there's this serious memory leak or something taking place in Zandronum.

Unfortunately the demo link has died and I don't have the demo on this new laptop of mine, which is a shame since the demo really captured the issue.

Here are my laptop specs:

Windows 8.1 64-bit
8.00 GB RAM
Intel Core i5-5200U CPU @ 2.20GHz
NVIDIA GeForce 820M GPU with 2GB DDR3 VRAM

But since I'm unable to reproduce this issue on my own server I don't really know what to do anymore from here on.

(0012859)
unknownna   
2015-07-12 01:32   
(edited on: 2015-07-13 06:34)
One thing I observed is that pressing tab to list commands in the console seemingly triggers the lag after being on the server for a while.

Could it be that this issue has something to do with the console accumulating memory when printing messages and potentially not freeing it?

Since messages are printed when players join the game, when items are picked up and when flags are taken/dropped/returned it would make sense that it would lag then.

(0012895)
unknownna   
2015-07-12 15:48   
(edited on: 2015-07-13 09:47)
Using this binary I was able to induce tons of CPU-like lag when I pressed tab to list commands in the console after 10 minutes or so due to the debug messages that had piled up in the console.

Actually, it already starts to lag after 2 minutes. And it seemingly only lags if cl_capfps is set to 1.

I can confirm that the CPU and memory usage gradually increases when the console is flooded with messages. It's unplayable after 10-15 minutes if cl_capfps is set to 1.

Quote from unknownna
And it seemingly only lags if cl_capfps is set to 1.

After 15 minutes it also lags when cl_capfps is set to 0.

And using the "clear" command in the console doesn't do anything either. It still lags a lot.

Is it possible to have it print the debug messages offline as well? Perhaps it's a (G)ZDoom issue.

Yep, every message that is printed after it has started to lag a lot will cause the client to freeze for a few tics. If you disconnect from the server it also lags offline.

(0012930)
unknownna   
2015-07-14 13:32   
(edited on: 2015-07-14 14:31)
It seems that (G)ZDoom has added a new console buffer, which should resolve this issue. If you decide to look into this issue, you could probably increase the buffer in the meantime like in ZDaemon until Zandronum catches up with (G)ZDoom.

Playing on a high-intensity CTF server for 2 hours is the equivalent of having your console flooded with debug messages, but with obituaries, pickup messages and flag messages instead.

In particular, this part of the new buffer seems crucial:

//==========================================================================
//
// Delete old content if number of lines gets too large
//
//==========================================================================

void FConsoleBuffer::ResizeBuffer(unsigned newsize)
{
    if (mConsoleText.Size() > newsize)
    {
        unsigned todelete = mConsoleText.Size() - newsize;
        mConsoleText.Delete(0, todelete);
        mBufferWasCleared = true;
    }
}

Now, I don't know how to read code, but apparently this should prevent the console memory from getting too big, right?

Actually, I was able to reproduce this issue in the latest ZDoom SVN build as well. I'll investigate this issue further.

This doesn't happen in ZDaemon because the old lines are simply deleted and cleared from the buffer it seems, thus the gameplay remains 100% smooth there.

(0012931)
unknownna   
2015-07-14 16:29   
(edited on: 2015-07-14 16:31)
'http://forum.zdoom.org/viewtopic.php?f=2&t=49042 [^]'

If ZDoom won't fix this, we need to add an option that allows us to have the ZDaemon behavior.

(0012939)
unknownna   
2015-07-14 19:49   
(edited on: 2015-07-16 11:26)
Fixed.

'http://zdoom.org/Changelog/c677dd3/files [^]'
'https://github.com/rheit/zdoom/commit/c677dd37f5ee02d126244f1d15f5854b64edb885 [^]'

Using zdoom-2.8pre-1669-gadd52d4.7z I can confirm that the issue has been resolved. The lag is gone.

Torr, we've got to backport this, we just have to. Please consider backporting this as soon as possible, if possible.

(0012955)
Edward-san   
2015-07-16 12:29   
(edited on: 2015-07-16 16:10)
Ported the change to the sandbox, here, for testing.

unknownna requested to see this ported into 2.1, so I managed to do it, but required some prior changes. See here.

I still need someone to build the involved changeset ( 7ce4fb6 ).

Here's a build from WaTaKiD:'https://www.dropbox.com/s/b2agi03335hfjk0/zandronum-2.1.1-r150716-1247-7ce4fb6-windows.zip?dl=0 [^]'

(0012956)
unknownna   
2015-07-16 19:14   
(edited on: 2015-07-16 19:58)
Yeah, that build fixed the issue (thanks, WaTaKiD!). It's now as smooth as ZDaemon. The lag is gone. Great job, Edward-san! There's only one minor side effect of the new behavior:

Quote from unknownna
Quote from Graf Zahl
Quote from unknownna
However, it takes ages for it to generate an error report now if the console was full of stuff before the crash occurred. But I suppose it's fine for most cases though. It'll only take a while if it crashes after hours of play.

Out of curiosity, how long does it take? Several seconds, a minute or even more?

It took around 36 seconds for it to generate the report when crashing after having copy-pasted the command in the OP. That's the equivalence of having played for around 1.5-2 hours on a high-intensity Zandronum CTF server I think.

So if it crashes after playing for a long time it takes a while for it to generate an error report due to how slow the RichEdit control is.

(0015165)
Torr Samaho   
2016-07-02 11:20   
I transplanted the ZDoom fix to 3.0.
(0015175)
WaTaKiD   
2016-07-02 15:39   
added in 3.0 with:'https://bitbucket.org/Torr_Samaho/zandronum/commits/1835e73c6b2bd91cbbc034826dbcccf34eed1387 [^]'
(0015754)
unknownna   
2016-10-04 15:12   
Hey, I just wanted to let you guys know that this seems to have been fixed now (tested with 3.0-alpha-160814-2010).

One thing though: It would probably be best to have a text somewhere in the error window that says "Generating crash report, please wait." or something like that. I think that to the average user it would look confusing to just see a bunch of commands stream down the window very fast without any further explanation on what's going on. Presumably the user would just close the window before Zandronum got a chance to generate the report.

Anyway, great job, and good luck with further developments!
(0016723)
Ru5tK1ng   
2017-01-30 01:11   
Closing based off of unknownna's testing.