MegaMek / megamek

MegaMek is a networked Java clone of BattleTech, a turn-based sci-fi boardgame for 2+ players. Fight using giant robots, tanks, and/or infantry on a hex-based map.
http://www.megamek.org
GNU General Public License v2.0
288 stars 277 forks source link

[BUG 49.16 - J17] - Princess Freezes More Often. 3 game logs attached. #4884

Open Thom293 opened 8 months ago

Thom293 commented 8 months ago

11:21:29,238 INFO [megamek.MegaMek] {main} megamek.MegaMek.initializeLogging(MegaMek.java:118) - Starting MegaMek v0.49.16-SNAPSHOT Build Date: 2023-10-30T01:09:03.342884900 Today: 2023-11-10 Origin Project: MegaMek Java Vendor: Eclipse Adoptium Java Version: 17.0.7 Platform: Windows 10 10.0 (amd64) System Locale: en_US Total memory available to MegaMek: 8 GB

As has been reported both here and in discord, Princess is freezing more often. See e.g. #4882 #4858. Not sure if those are related, but they are recent.

Sometimes she will freeze multiple times in the same game. Its very noticeable in bot v bot testing since you can do more games quickly, but is happening in regular play too. At least in my tests, kicking her and replacing allowed the game to continue.

I ran 10 tests and got 3 freezes. I was running other tests earlier and I think that frequency is lower than I was experiencing before. But seems like something every 2-3 game on average. More than once she froze more than once in the same match.

I have attached a zip with the logs for the 3 freezes, an autosave for one of the freezes, and a savegame for a bot v bot match and the custom mechs used in it, if you want to run tests yourself. Just load the "customlance" save, select a bot for each of the 2 teams and hit start. At least on my computer each game takes about 2 minutes.

00 Bot Freeze.zip

Sleet01 commented 8 months ago

Loading the included save game, I got a freeze on turn 10. It looks like the issue occurs immediately after a KD unit attempts to stand. Looking at Princess's logic closer...

Thom293 commented 8 months ago

Ok. I didn't think to save the other two autsaves, but I think one of the freezes occurred on Round 5, before the two sides were ever engaged.

Sleet01 commented 8 months ago

Ok. I didn't think to save the other two autsaves, but I think one of the freezes occurred on Round 5, before the two sides were ever engaged.

I'll run this a few more times and see what I get.

Sleet01 commented 8 months ago

Well, after several more iterations I haven't got any more hangs. The first time it looked like the server was just waiting for a response, not actually "hung" per se - and kicking and re-adding the bots fixed the issue in that case.

I'm guessing this is some kind of timing issue, where Princess misses a phase change somehow, but without further instances it'll be tough to track down.

Thom293 commented 8 months ago

You didnt get any freezes? Odd. I can get more. But yes it seemed to often (but not always) be after the phase where a mech stood up.

I assumed the logs would show what happened which is why I didnt bother with the saves at first. Guess not.

Sleet01 commented 8 months ago

@Thom293 Can you do me a favor? Unzip and copy this file over your log4j2.xml file (should be in ...\mmconf\ in your installed directory) and try running whichever save file gives you the most consistent freezes? Then post a zipped copy of the resulting megemek.log here? That will switch the logging level to "debug" which hopefully will give some more insight.

log4j2.zip

Thom293 commented 8 months ago

Yes! Ill run some more tests sometime this weekend and make sure to do that. Ill make sure to grab the saves too.

Thom293 commented 8 months ago

Here is another with detailed logging turned on. Game was supposed to end on Round 25 automatically. Freeze on R24. FreezeDetailedLog.zip @Sleet01

Ill try to get another if I can.

Thom293 commented 8 months ago

and another. Round 2, before any combat. r2 freezes.zip

Thom293 commented 8 months ago

Another freeze on Round1.
r1freeze.zip

and same game round 10

samegameR10freeze.zip

Sleet01 commented 8 months ago

Another freeze on Round1. r1freeze.zip

and same game round 10

samegameR10freeze.zip

I haven't gotten any freezes on this save and played past round 10. I also haven't seen any freezes on the other saves either. I'd guess there's some difference between our setups that aren't captured in the MegaMek logs, or otherwise some environmental difference that I'm not seeing.

I'll give this another go tomorrow - it's especially annoying because I did see a freeze the very first time, and then never again.

Thom293 commented 8 months ago

Yeah that's odd. I guess the best way maybe to just load the first save I posted and let princess run 10ish battles on auto they take about 3 minutes. Should get 2 or so out of that many.

PhoenixHeart512 commented 5 months ago

Environment: 10:50:38,070 INFO [megamek.MegaMek] {main} megamek.MegaMek.initializeLogging(MegaMek.java:118) - Starting MegaMek v0.49.18-SNAPSHOT Build Date: 2024-02-09T01:06:06.158121400 Today: 2024-02-09 Origin Project: MegaMekLab Java Vendor: Eclipse Adoptium Java Version: 17.0.6 Platform: Windows 10 10.0 (amd64) System Locale: en_US Total memory available to MegaMek: 4 GB

Using the nightly build downloaded on 2/9/2024

I happened to have debug logging enabled and the freeze occurred, attaching log and save files. I also have paranoid autosave on, and since this was the first turn of the battle I've simply included all 3 autosaves from this turn.

Note: In my previous testings for this issue, it is not consistent but can happen randomly on the same file and same movement. Last time I was actively trying to repro the issue, I loaded and replayed the same turn 10 times in a row, and it froze 2 of those times, so a single save file could generate the freeze even if it doesn't happen on the first try.

PrincessFiringPhaseFreeze.zip

Thom293 commented 3 months ago

So Im stuck waiting somewhere so thought I would update this. This freezing almost completely disappeard over 49.17 and 49.18. Not completely, but it was very very rare. And we ran a lot of large battle tests testing Sleets new firing and ammo code.

But in 49.19 - particularly the last few nightlies. Id guess since approximately the start of april - the freezing has returned with a vengance. Often twice in one game. I didnt get any saves because I was testing something else, but I will do so going forward.

Thom293 commented 3 months ago

Sorry to be clear, although a minor annoyance, this isnt game breaking. There is a simple workaround of just kicking a reloading bot. Should not impede schedules, IMHO.

Sleet01 commented 3 months ago

So Im stuck waiting somewhere so thought I would update this. This freezing almost completely disappeard over 49.17 and 49.18. Not completely, but it was very very rare. And we ran a lot of large battle tests testing Sleets new firing and ammo code.

But in 49.19 - particularly the last few nightlies. Id guess since approximately the start of april - the freezing has returned with a vengance. Often twice in one game. I didnt get any saves because I was testing something else, but I will do so going forward.

There's some new pathing code in play now, and pathing was one of the big offenders that would cause Princess to basically go silent or disconnect: Uncaught exceptions in that code would cause her to revert to a waiting state, but would not be caught by the main game thread. I tried to wrap as much of that in Try/Catch blocks as I could, but there are probably a few where she just... stops.

Thom293 commented 3 months ago

Based on the above, I dont think saves will help you, but here is a log that should have a few freezes scattered throughout.

megamek.log