Anonymous | Login | Signup for a new account | 2024-04-25 01:16 UTC |
My View | View Issues | Change Log | Roadmap | Zandronum Issue Support Ranking | Rules | My Account |
View Issue Details [ Jump to Notes ] | [ Issue History ] [ Print ] | ||||||||
ID | Project | Category | View Status | Date Submitted | Last Update | ||||
0003132 | Zandronum | [All Projects] Bug | public | 2017-05-10 16:04 | 2018-09-30 21:43 | ||||
Reporter | Cutman | ||||||||
Assigned To | Torr Samaho | ||||||||
Priority | urgent | Severity | major | Reproducibility | random | ||||
Status | closed | Resolution | fixed | ||||||
Platform | OS | OS Version | |||||||
Product Version | 3.0-beta | ||||||||
Target Version | 3.0 | Fixed in Version | 3.0 | ||||||
Summary | 0003132: P_PlayerThink errors on map change | ||||||||
Description | We've been getting a lot of P_PlayerThink errors when a new map begins in MM8BDM. It used to happen before but very infrequently and usually when additional mods were run, but now it's happening way more than usual with even less players. Trying to pinpint the issue is a pain. I've been slowly taking 8bdm apart to see what the problem is. I axed the scripts, DECORATE, skins, everything until just the maps remained, and even now I'm not sure if they are what is causing the bug. It seems to happen always if you have a ton of bots on the server and change to a map (see the custom one below, it's UDMF and has no scripts). Hopefully reproducing this with bots is enough to figure out what is going on. | ||||||||
Steps To Reproduce | 1. Download the wad. Host a server MAP01, deathmatch. No fraglimit yet. 2. Join the server, add a ton of bots. I'm talking like 50+. A lot of telefragging will be going on in MAP01 but don't worry about that. 3. Set the fraglimit to 1. SOMEONE will get it, and the game will start transitioning to MAP02 (the wad replaces MAP02 with a new empty map with DM starts). 4. When MAP02 starts you should get a flood of P_PlayerThink errors. | ||||||||
Additional Information | I must stress that this is not just happening with bots. With around 6 players in our 8BDM beta build it happens after every map change, even after taking out DECORATE and ACS. | ||||||||
Attached Files | unnamedtest.wad [^] (31,696 bytes) 2017-05-10 16:04 cvartest.wad [^] (3,688 bytes) 2017-05-11 22:34 | ||||||||
Notes | |
(0017620) jdagenet (reporter) 2017-05-11 01:30 |
I'm unable to reproduce this. |
(0017621) EnsaladaDeTomate (reporter) 2017-05-11 02:37 edited on: 2017-05-11 02:48 |
I think this one is related to this aswell:'https://zandronum.com/tracker/view.php?id=2552 [^]' |
(0017622) jdagenet (reporter) 2017-05-11 04:17 |
From reading that ticket it appears the problem was fixed at one point but resurfaced. I find it strange that Cutman is able to reproduce it using the steps above but I get nothing. Makes me think it's something specific like the ini or maybe something else. |
(0017624) Cutman (reporter) 2017-05-11 10:59 |
I just tried again using a fresh Zandronum folder and ini file. This time I managed to get it to happen by just doing changemap map01 in coop while the bots were in the game, didn't even need the wad file. 'http://imgur.com/a/J3Kd0 [^]' |
(0017626) Cutman (reporter) 2017-05-11 18:29 edited on: 2017-05-11 18:30 |
FINALLY I found the culprit: CVARINFO. My trial and error had me stripping mm8bdm until there were only a few lumps left, but the bug went away when I took CVARINFO out of the pk3. I tried putting the lump on it's own into a wad for Doom2 and what do you know, the bug happened. Don't need bots this time (the bot issue may be unrelated). 'http://cutstuff.net/public/cvartest.wad [^]' 1. Download the file. Run Doom2 with it just to make sure the cvars enter the ini file (not sure if required). 2. Host a deathmatch server with cvartest.wad. Then have 6+ clients join the game (can be from your own machine). 3. Set the fraglimit to 1 and get a kill (or use changemap map02 on the server console). 4. The map will change and you should see some p_playerthink errors on one/some of your clients. I am not sure if a specific custom cvar is causing the issue or if it's because there's a ton of them in this CVARINFO lump. Hopefully you guys can figure that out! |
(0017627) jdagenet (reporter) 2017-05-11 22:01 |
Upon further testing, it appears that the number of CVARs in the CVARINFO lump contributes to the issue, not any one specific CVAR. I doubt the type of CVAR has anything to do with it, the issue triggered for me using 68 "user int" type CVARs. |
(0017633) Torr Samaho (administrator) 2017-05-13 10:27 |
I can't reproduce the problem under Windows with six local clients and a server started withzandronum -file cvartest.wad -host +deathmatch 1 -nomonsters +fraglimit 1 Any other ideas how to reproduce this? |
(0017634) Cutman (reporter) 2017-05-13 10:46 |
I was using: zandronum -deathmatch 1 -host 64 -file cvartest.wad And changed the fraglimit in the server window, though that probably doesn't matter. Here is the ini file I was using for both the server host and clients (started off as a blank one)'https://hastebin.com/utodewired.makefile [^]' |
(0017635) Torr Samaho (administrator) 2017-05-13 10:52 |
No, even with that ini and changing the fraglimit in the server window, I can't reproduce the problem here with six local clients. Which Zandronum binary did you use? |
(0017637) Cutman (reporter) 2017-05-13 11:13 |
The version number on the console is "v3.0-alpha (2.8pre-441-g458e1b1) 170416-0710", should be the same windows build listed on the website:'http://zandronum.com/downloads/testing/3.0/ZandroDev3.0-170416-0710windows.zip [^]' |
(0017639) Torr Samaho (administrator) 2017-05-13 11:18 |
I can't reproduce the problem with that version either. Does it happen every time or do you need to try more than once? 0003132:0017626 sounds like it should happen always on at least on of the clients. |
(0017640) Cutman (reporter) 2017-05-13 11:21 |
Yeah it happens every time for me, every client is getting some form of playerthink error. I'll upload a video of the whole process, maybe that will help. |
(0017641) Cutman (reporter) 2017-05-13 11:32 |
'https://www.youtube.com/watch?v=C-hMyKCECi8 [^]' ignore the steps setting my max allowed ip addresses, that was just something I forgot after resetting my ini again. |
(0017643) Torr Samaho (administrator) 2017-05-13 12:36 |
Still works fine for me, but I'm beginning to think that this has nothing to do with CVARINFO in particular, but is related to full updates that need more than one packet, which will happen for sure with the amount of user cvars you have, in combination with packet loss, which doesn't seem to happen on my machine under these circumstances, but may happen on your machine. Can you start one of the six clients with the extra option -debugfile and upload the resulting file "debug0.txt", which the client creates? Please also record a client side demo. Hopefully, the issue is reproducible when playing the demo. On a side note, the problem in the video looks like only a cosmetic issue, i.e. you have a very short one time burst of warnings after a map change. The gameplay doesn't seem to be affected here since the warnings stop immediately. |
(0017645) Cutman (reporter) 2017-05-13 12:47 edited on: 2017-05-13 12:49 |
Sure, but it's kinda ugly and happens every game. You might only get one bug report about this but fixing this will prevent me from getting tons of them later ;) 'https://hastebin.com/nosarapaqu.sql [^]' Here's the debug file while I repeated the same process in the video. Edit: Oops forgot the demo. Lemmie try that again. |
(0017647) Cutman (reporter) 2017-05-13 12:56 |
'https://hastebin.com/vunomakuse.sql [^]' 'http://cutstuff.net/public/NEWDEMO.lmp [^]' |
(0017648) Torr Samaho (administrator) 2017-05-13 13:00 |
Yeah, your debug file confirms that you have missing packets, so it's likely related to them. With your demo I also get the error messages. So this should be enough for me to investigate further what's happening. |
(0017650) Torr Samaho (administrator) 2017-05-13 14:43 |
The error messages that could occur after a map change before the full snapshot was received should be fixed now. |
(0017651) Cutman (reporter) 2017-05-13 14:49 |
If you need me specifically to test it, please provide a build. |
(0017653) Torr Samaho (administrator) 2017-05-13 14:56 |
Here is a binary with the fix. Please check if it fixes the issue for you. |
(0017654) Cutman (reporter) 2017-05-13 15:00 |
Testing using the same method, no error messages popped up on any of the clients. Seems to be fixed! |
(0017658) Ru5tK1ng (updater) 2017-05-13 20:26 |
Thanks for testing. Reopen if needed in the future. |
(0017756) Cutman (reporter) 2017-05-24 19:16 edited on: 2017-05-24 19:30 |
We're not out of the woods yet I'm afraid, another related issue has popped up. Still related to CVARINFO or at least whatever CVARINFO is doing to cause it. Some players cannot join servers correctly if other players are in the server (works fine for them if the server is empty). They get stuck on the console, can hear music but no gameplay happens their end. This only happens when this CVARINFO is loaded. Other players see them as live and in game and can even be killed (if auto join is enabled). This is what the user sees:'http://i.imgur.com/EX7pqkx.png [^]' I went ahead and got them to test the build posted above too. Still no good. I hosted a server with the build, joined myself and had them join. They had the issue and recorded a demo file + used debugfile. Here are the results: cvartest wad (NOTE: Changed slightly from the attached file):'http://cutstuff.net/public/cvartest.wad [^]' debugfile:'https://pastebin.com/raw/HsjmauHx [^]' demo file:'http://cutstuff.net/public/clausdemo.lmp [^]' This is happening to handful of players, and should be looked into before the next public zandronum build. Edit: If they join the server with zero players, then other players join in, they will get stuck on map change. |
(0017757) Ru5tK1ng (updater) 2017-05-25 01:17 |
So this new issue didn't occur until after torr fixed the P_PlayerThink errors? Or were you using an older build when it came up? |
(0017758) Cutman (reporter) 2017-05-25 01:29 |
It happens in both the current public 3.0 build and the one Torr posted. |
(0017761) Cutman (reporter) 2017-05-25 19:37 |
We tested older Zandronum builds too. It was fine up until this one, 170205-2117 'http://zandronum.com/downloads/testing/3.0/ZandroDev3.0-170205-2117windows.zip [^]' By the way when I said a handful of people, that number is actually increasing a lot since 8bdm's new version release. I highly recommend a new zandronum build after getting to the bottom of this, as long as there's nothing else urgent that needs looking at. |
(0017762) Ru5tK1ng (updater) 2017-05-25 20:45 |
Can you try this build provided by watakid:'https://www.dropbox.com/s/85ze5s41su013gf/zandronum-3.0-r170122-1540-1fde0c6-windows.zip?dl=0 [^]' |
(0017763) Cutman (reporter) 2017-05-25 21:02 |
Tested, it is working fine in that build. |
(0017764) Ru5tK1ng (updater) 2017-05-25 22:24 |
Then as suspected by wata and myself, the culprit is most likely:'https://bitbucket.org/Torr_Samaho/zandronum/commits/a8335806821b23c1d8565211a6e622d5b59918d2 [^]' |
(0017767) Torr Samaho (administrator) 2017-05-27 09:16 |
I think I know what's happening: SERVERCOMMANDS_SetAllPlayerUserInfo and SERVERCOMMANDS_SetPlayerUserInfo are putting all information into one network packet, even if this leads to packets that exceeded the sv_maxpacketsize. We'll have to split this over multiple packets. |
(0017773) Torr Samaho (administrator) 2017-05-28 13:45 |
Can you check if this fixes the issue? |
(0017777) Cutman (reporter) 2017-05-28 16:09 |
That fixed it! Tested with LMS (round resetting) and map switching to make sure they could always get in. |
(0017799) Ru5tK1ng (updater) 2017-06-05 00:09 |
The following commits for that build were added: 'https://bitbucket.org/Torr_Samaho/zandronum/commits/19d89d1637b1c2965ca08b9370efe64aa01c9cce [^]' 'https://bitbucket.org/Torr_Samaho/zandronum/commits/beaf2601443cd83710fefe324a4ec97242e373e8 [^]' 'https://bitbucket.org/Torr_Samaho/zandronum/commits/befdc069426aa69a65f170f261c6591c38d51660 [^]' |
(0017804) Cutman (reporter) 2017-06-06 16:49 |
Cool, hope you guys can get a new public build up soon. A lot of players (I've counted 8 so far) cannot play the game while this is happening. It sucks cause a lot of those CVARs aren't even used in multiplayer, and it's not like I can release a small patch wad file to remove them (as far as I know?) |
(0017805) Torr Samaho (administrator) 2017-06-06 18:43 |
If you don't need the values in multiplayer, you could convert them to server cvars. With a user cvar, you have one separate value for each player. Unless you need that, you should be able to use server cvars. The next build is planned as soon as we have taken care of 0003124. |
(0017809) Dusk (developer) 2017-06-08 19:40 edited on: 2017-06-08 19:40 |
Nice catch! I took and gave this one a bit of a refactor because I suspect that the math in that commit is going to break sometime. 'https://bitbucket.org/zandronum/zandronum-sandbox/commits/89336095880a6a47c1f9d67fd14df0deb68d6ce3 [^]' 'https://bitbucket.org/zandronum/zandronum-sandbox/commits/a7641eb196f015e2aa39b625ecc50fe546c0177f [^]' 'https://bitbucket.org/zandronum/zandronum-sandbox/commits/3c091d308689a477b14750c98cde13d1de09820a [^]' 'https://bitbucket.org/zandronum/zandronum-sandbox/commits/206242baeacd5c3638080086e452b4301fe8d8a8 [^]' I gave this a run with a cvarinfo with 500 cvars and it appears to still work as intended. Can someone confirm? |
(0017810) Cutman (reporter) 2017-06-08 20:09 |
Drop me a build if you would like me to test with the people who suffer with this issue. |
(0017837) Torr Samaho (administrator) 2017-06-18 16:59 |
Dusk, thanks! I added your patches. |
(0017865) Cutman (reporter) 2017-06-22 02:47 |
Sorry to be the bearer of bad news again but someone else is now having connection issues with 8bdm v5b with the latest public zandronum build (170618-1927). I had him test the cvartest.wad and as expected the culprit is the cvarinfo stuff. There is a difference here though, he truly just gets stuck in the requesting snapshot screen and doesn't even appear in game my end or hear music while in the console etc. In my server log I get the following message "Connect (v3.0-alpha): 24.3.40.196:10667 Unfinished connection from 24.3.40.196:10667 timed out." I got him to do a logfile, not sure if it shows much information:'https://hastebin.com/ixoripaqiy.go [^]' |
(0017867) Torr Samaho (administrator) 2017-06-22 06:07 |
Was this any better in the older build I posted, i.e. #17773? What is the value of sv_maxpacketsize on the server? |
(0017871) Cutman (reporter) 2017-06-22 13:37 |
Sorry could you link that build again? sv_maxpacketsize was 1024 on the servers tested (both mine and TSPG servers) |
(0017874) Ru5tK1ng (updater) 2017-06-22 16:26 |
He means this build: 'http://www.mediafire.com/file/k77lwk52s55q5fm/ZandroDev3.0-LargeUserinfoFixTest.7z [^]' |
(0017875) Cutman (reporter) 2017-06-22 17:25 |
We tried that build and the same issue happens, stuck on getting snapshot. |
(0017893) Torr Samaho (administrator) 2017-06-24 13:05 |
And the problem with getting stuck at the snapshot happens with just cvartest.wad loaded (no other mods, doom2.wad as IWAD, map01) and vanishes if cvartest.wad is not loaded? |
(0017894) Cutman (reporter) 2017-06-24 13:10 |
Yes, with vanilla Doom2 MAP01 he was able to connect fine. Including the wad he gets stuck at the snapshot. Interestingly if the server hosted with the cvartest WAD and he didn't launch with it, it actually allowed him to connect and play just fine. |
(0017895) Torr Samaho (administrator) 2017-06-24 14:36 |
Is his console just repeatedly saying "Authenticating level..." when he is stuck? Does it always happen or does it work sometimes? No other players need to be in the server to get stuck? |
(0017896) Cutman (reporter) 2017-06-24 14:48 |
His console just says "Requesting Snapshot" endlessly. It works sometimes when the server is empty, but not always. If I was in the server at the time he couldn't ever connect while he was running the wad. |
(0017897) Cutman (reporter) 2017-06-24 15:02 |
Quick update, two people are still having the issue still. The other person is the one who submitted ticket 0003069 as is most likely the same issue as that one. 'https://puu.sh/wt3Jw/a1b993a26c.png [^]' |
(0017899) Torr Samaho (administrator) 2017-06-24 17:41 |
Turned out that there were problems with packet loss while joining the server. Please test if this fixes the issue. |
(0017900) Cutman (reporter) 2017-06-24 18:44 |
It didn't. Same snapshot issue and "Unfinished connection from 24.3.40.196:10667 timed out." on my server. |
(0017903) Torr Samaho (administrator) 2017-06-25 07:31 |
I found another issue. The client was still sending too large packets. Please check if this fixes the issue. |
(0017921) Cutman (reporter) 2017-06-25 17:37 |
That fixed it, tested with both parties! They were able to connect properly. I also notice the server console got flooded with a bunch of CVARs and playerinfo. |
(0017928) Torr Samaho (administrator) 2017-06-25 20:09 |
I'm glad to hear that it works! And sorry about the console flood. I added debug output to check whether the packet splitting still transfers the full user info. |
(0017956) Ru5tK1ng (updater) 2017-06-30 23:33 |
I spoke with cutman and he hasn't heard of any issues with his playerbase. I'll mark this as resolved, hopefully for good. |
This issue is already marked as resolved. If you feel that is not the case, please reopen it and explain why. |
|
Supporters: | No one explicitly supports this issue yet. |
Opponents: | No one explicitly opposes this issue yet. |
Issue History | |||
Date Modified | Username | Field | Change |
2017-05-10 16:04 | Cutman | New Issue | |
2017-05-10 16:04 | Cutman | File Added: unnamedtest.wad | |
2017-05-11 01:30 | jdagenet | Note Added: 0017620 | |
2017-05-11 02:37 | EnsaladaDeTomate | Note Added: 0017621 | |
2017-05-11 02:48 | EnsaladaDeTomate | Note Edited: 0017621 | View Revisions |
2017-05-11 04:17 | jdagenet | Note Added: 0017622 | |
2017-05-11 10:59 | Cutman | Note Added: 0017624 | |
2017-05-11 18:29 | Cutman | Note Added: 0017626 | |
2017-05-11 18:30 | Cutman | Note Edited: 0017626 | View Revisions |
2017-05-11 22:01 | jdagenet | Note Added: 0017627 | |
2017-05-11 22:34 | WaTaKiD | File Added: cvartest.wad | |
2017-05-13 10:27 | Torr Samaho | Note Added: 0017633 | |
2017-05-13 10:28 | Torr Samaho | Assigned To | => Torr Samaho |
2017-05-13 10:28 | Torr Samaho | Status | new => feedback |
2017-05-13 10:28 | Torr Samaho | Target Version | => 3.0 |
2017-05-13 10:46 | Cutman | Note Added: 0017634 | |
2017-05-13 10:46 | Cutman | Status | feedback => assigned |
2017-05-13 10:52 | Torr Samaho | Note Added: 0017635 | |
2017-05-13 10:52 | Torr Samaho | Status | assigned => feedback |
2017-05-13 11:13 | Cutman | Note Added: 0017637 | |
2017-05-13 11:13 | Cutman | Status | feedback => assigned |
2017-05-13 11:18 | Torr Samaho | Note Added: 0017639 | |
2017-05-13 11:21 | Cutman | Note Added: 0017640 | |
2017-05-13 11:32 | Cutman | Note Added: 0017641 | |
2017-05-13 12:36 | Torr Samaho | Note Added: 0017643 | |
2017-05-13 12:47 | Cutman | Note Added: 0017645 | |
2017-05-13 12:49 | Cutman | Note Edited: 0017645 | View Revisions |
2017-05-13 12:56 | Cutman | Note Added: 0017647 | |
2017-05-13 13:00 | Torr Samaho | Note Added: 0017648 | |
2017-05-13 14:43 | Torr Samaho | Note Added: 0017650 | |
2017-05-13 14:43 | Torr Samaho | Status | assigned => needs testing |
2017-05-13 14:49 | Cutman | Note Added: 0017651 | |
2017-05-13 14:56 | Torr Samaho | Note Added: 0017653 | |
2017-05-13 15:00 | Cutman | Note Added: 0017654 | |
2017-05-13 20:26 | Ru5tK1ng | Note Added: 0017658 | |
2017-05-13 20:26 | Ru5tK1ng | Status | needs testing => resolved |
2017-05-13 20:26 | Ru5tK1ng | Resolution | open => fixed |
2017-05-13 20:26 | Ru5tK1ng | Fixed in Version | => 3.0 |
2017-05-24 19:16 | Cutman | Note Added: 0017756 | |
2017-05-24 19:16 | Cutman | Status | resolved => feedback |
2017-05-24 19:16 | Cutman | Resolution | fixed => reopened |
2017-05-24 19:29 | Cutman | Note Edited: 0017756 | View Revisions |
2017-05-24 19:30 | Cutman | Note Edited: 0017756 | View Revisions |
2017-05-25 01:17 | Ru5tK1ng | Note Added: 0017757 | |
2017-05-25 01:29 | Cutman | Note Added: 0017758 | |
2017-05-25 01:29 | Cutman | Status | feedback => assigned |
2017-05-25 02:30 | Ru5tK1ng | Note Added: 0017759 | |
2017-05-25 02:43 | Ru5tK1ng | Note Edited: 0017759 | View Revisions |
2017-05-25 02:46 | Ru5tK1ng | Note Deleted: 0017759 | |
2017-05-25 19:37 | Cutman | Note Added: 0017761 | |
2017-05-25 20:45 | Ru5tK1ng | Note Added: 0017762 | |
2017-05-25 21:02 | Cutman | Note Added: 0017763 | |
2017-05-25 22:24 | Ru5tK1ng | Note Added: 0017764 | |
2017-05-27 09:16 | Torr Samaho | Note Added: 0017767 | |
2017-05-28 13:45 | Torr Samaho | Note Added: 0017773 | |
2017-05-28 16:09 | Cutman | Note Added: 0017777 | |
2017-06-05 00:09 | Ru5tK1ng | Note Added: 0017799 | |
2017-06-05 00:10 | Ru5tK1ng | Status | assigned => needs testing |
2017-06-06 16:49 | Cutman | Note Added: 0017804 | |
2017-06-06 18:43 | Torr Samaho | Note Added: 0017805 | |
2017-06-08 19:40 | Dusk | Note Added: 0017809 | |
2017-06-08 19:40 | Dusk | Note Edited: 0017809 | View Revisions |
2017-06-08 20:09 | Cutman | Note Added: 0017810 | |
2017-06-18 16:59 | Torr Samaho | Note Added: 0017837 | |
2017-06-22 02:47 | Cutman | Note Added: 0017865 | |
2017-06-22 06:07 | Torr Samaho | Note Added: 0017867 | |
2017-06-22 13:37 | Cutman | Note Added: 0017871 | |
2017-06-22 16:26 | Ru5tK1ng | Note Added: 0017874 | |
2017-06-22 17:25 | Cutman | Note Added: 0017875 | |
2017-06-24 13:05 | Torr Samaho | Note Added: 0017893 | |
2017-06-24 13:10 | Cutman | Note Added: 0017894 | |
2017-06-24 14:36 | Torr Samaho | Note Added: 0017895 | |
2017-06-24 14:48 | Cutman | Note Added: 0017896 | |
2017-06-24 15:02 | Cutman | Note Added: 0017897 | |
2017-06-24 17:41 | Torr Samaho | Note Added: 0017899 | |
2017-06-24 18:44 | Cutman | Note Added: 0017900 | |
2017-06-25 07:31 | Torr Samaho | Note Added: 0017903 | |
2017-06-25 17:37 | Cutman | Note Added: 0017921 | |
2017-06-25 20:09 | Torr Samaho | Note Added: 0017928 | |
2017-06-30 23:33 | Ru5tK1ng | Note Added: 0017956 | |
2017-06-30 23:33 | Ru5tK1ng | Status | needs testing => resolved |
2017-06-30 23:33 | Ru5tK1ng | Resolution | reopened => fixed |
2018-09-30 21:43 | Blzut3 | Status | resolved => closed |
Copyright © 2000 - 2024 MantisBT Team |