Benjozork commented 3 years ago

Mod Version

latest master commit

Describe the bug

To Reproduce

Perform a long (>2hr) flight

Expected behavior

CoherentGTDraw stays consistent throughout the flight

Actual behavior

CoherentGTDraw slowly gets higher

Discord username (if different from GitHub): someperson#4953

Benjozork commented 3 years ago

If you experience this issue, please leave a comment with the following information:

Contents of build-info.json in our Community folder / A32NX
Duration of your flight

CaptainRafael commented 3 years ago

{ "built": "2021-02-02T21:59:06+00:00", "ref": "fbw", "sha": "0d4237c4f2045c296e059d8c71d72c004644084f", "actor": "nistei", "event_name": "manual" } Duration : 1h20 ( expected 1h35)

PierreLabs commented 3 years ago

I had a few crashes this afternoon with the cfbw version, and with the WT CJ4 latest version as well. My build-info is not the same since I've updated since then, so I won't put it here. but I will the log from the event viewer. Happened each time past an hour into the flight. CoherentGTCore.dll is the culprit.

Each time it's been a sudden freeze followed by a CTD

Nom de l’application défaillante FlightSimulator.exe, version : 0.0.0.0, horodatage : 0x5fda32ba
Nom du module défaillant : CoherentGTCore.dll, version : 0.0.0.0, horodatage : 0x5fc6a9c9
Code d’exception : 0xc0000005
Décalage d’erreur : 0x00000000001aa1f6
ID du processus défaillant : 0x2c48
Heure de début de l’application défaillante : 0x01d6f9765ff47f58
Chemin d’accès de l’application défaillante : C:\Program Files\WindowsApps\Microsoft.FlightSimulator_1.12.13.0_x64__8wekyb3d8bbwe\FlightSimulator.exe
Chemin d’accès du module défaillant: C:\Program Files\WindowsApps\Microsoft.FlightSimulator_1.12.13.0_x64__8wekyb3d8bbwe\CoherentGTCore.dll
ID de rapport : ff9d3807-563b-432f-9755-7c8ed1587f36
Nom complet du package défaillant : Microsoft.FlightSimulator_1.12.13.0_x64__8wekyb3d8bbwe
ID de l’application relative au package défaillant : App

Discord username: Theodran#8339

Watsi01 commented 3 years ago

Can confirm that. Have that with every longer flight (1:45 or above).

XSJoJo commented 3 years ago

Can you folks upload a start of the flight/end of the flight screenshot of the in-game FPS overlay?

On Wed, Feb 3, 2021 at 9:14 AM RogePete notifications@github.com wrote:

Can confirm that. Have that with every longer flight (1:45 or above).

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/flybywiresim/a32nx/issues/3302#issuecomment-772321276, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAXBEQPVUGP6W7Q7H5WZGPTS5EAXDANCNFSM4W74OUPQ .

scottfranks84 commented 3 years ago

I had an FPS issue today which I think this is what you mean. Departed JFK to Cancun with 45-40 FPS- landing into Cancun 3.5 hours later dropped to under 30. And then 4 hours later back in JFK, I was getting 18-22 FPS on landing

rollonit commented 3 years ago

I can definitely confirm this issue. I had to abandon a VATSIM flight from KLAX to PHNL because two hours into the flight, the frame rate became unplayable. My build info: { "built": "2021-02-04T07:38:39+00:00", "ref": "fbw", "sha": "7746add237bbad5946edf0b75027f09a51f12ae0", "actor": "aguther", "event_name": "manual" } Flight time: 5:26, but I stopped around 2:10 because my frames dropped to around 5-10 fps.

holloman47 commented 3 years ago

I had this problem when I did a 3 HR EGKK-EDDL and returned ..by the time I got back to Gatwick it was like slow motion on approach..15fps!.Since then I have rebooted on the turnaround as a quick fix ..I was using A320NX dev..

CaptainRafael commented 3 years ago

{ "built": "2021-02-04T07:38:39+00:00", "ref": "fbw", "sha": "7746add237bbad5946edf0b75027f09a51f12ae0", "actor": "aguther", "event_name": "manual" }

1h34 flight 45/50 FPS on takeoff 10/20fps max on landing

PilotMathews commented 3 years ago

{ "built": "2021-02-03T19:03:44+00:00", "ref": "master", "sha": "b9245c886074dc9a8a8e6cdfd7724a5a3f8077c5", "actor": "Benjozork", "event_name": "manual" }

Flight Time: 04h06m Departure FPS: 40/45 Arrival FPS: 15/20

Note: Entire flight was conducted over ocean from YSSY to NFFN; therefore scenery was not a factor in FPS. Also having random flap extensions during cruise with only 2 contoller buttons assigned, however not sure if this is related...

Watsi01 commented 3 years ago

I'm wondering if this is an A32NX issue or a MSFS problem in general... I had this with other planes too though.

scottfranks84 commented 3 years ago

I had an FPS issue today which I think this is what you mean. Departed JFK to Cancun with 45-40 FPS- landing into Cancun 3.5 hours later dropped to under 30. And then 4 hours later back in JFK, I was getting 18-22 FPS on landing

Well...with my i7 8700 and 1070ti, I get 18-22fps everytime landing in JFK, regardless of how long have played.

Ahhh I used to get over 30. Hopefully it’s get fixed soon. Nice name btw lol

submetu commented 3 years ago

Hi guys, I had this issue twice now in the last two days. (This did not happen before). FPS issues start somewhere after 120 minutes of flight time. After around 140 minutes my fps drops to 3-5 and it becomes unplayable.

I then save the flight and restart msfs and load the flight. The fps issues go away. But its a pain when you are using vatsim etc.

Here is my build-info.json

{
  "built": "2021-02-04T07:38:39+00:00",
  "ref": "fbw",
  "sha": "7746add237bbad5946edf0b75027f09a51f12ae0",
  "actor": "aguther",
  "event_name": "manual"
}

omarsmak commented 3 years ago

I am wondering, although it makes sense to find the root cause but can this issue somehow be fixed by this PR https://github.com/flybywiresim/a32nx/pull/3262

Benjozork commented 3 years ago

The issue is looking more and more like the StatefulSimVar implementation brought along by the new RMP is somehow causing either GC lag or interval leaks.

BritishAvgeek commented 3 years ago

May or may not be of use, hopefully more useful than not though and people who know what this means can dissect it at least

Benjozork commented 3 years ago

What you linked is no longer an issue after recent optimisations. The current problem is caused by something else that was added recently.

pareil6 commented 3 years ago

I've given QA testers given builds of d53d3f73, c99e98b9 and 58226331 - that's the change before the RMP change, the RMP change, and a rough midpoint between now and the RMP change (including the EFB) respectively - to try and verify whether it is the RMP change, or if not, whether it was pre- or post-EFB merge.

theomessin commented 3 years ago

Hold up!

The only scientific approach to figure out whether the RMP is the root cause is to test with a revert:

Please do a clean install of commit aff960bf74a0a806cb56ae8a14d5990a6181dff9

[x] Take a screenshot of the MSFS FPS display after the aircraft has been started up (i.e. all displays on)
[x] Fly for at least 2 hours.
[x] Take a screenshot of the MSFS FPS display. The Coherent GT delay should now be a lot higher.

Now do a clean install of pull request #3355 (eee44d1bc44e368f763d2f2f7dde660bb1065df1)

This build is the exact same build as the previous one, minus just the RMP.

[x] Take a screenshot of the MSFS FPS display after the aircraft has been started up (i.e. all displays on)
[x] Fly the exact same route for at least 30 minutes more than what was needed to get the issue previously.
[x] If you get the issue at any point you can end the test. This means that the RMP is not the root cause.
[x] Take a screenshot of the MSFS FPS display. Is the Coherent GT delay back to normal?

Comment on this issue with your findings. Please provide annotated screenshots of each different stage (at least 4 different screenshots).

XSJoJo commented 3 years ago

Ok I looked at this some by inserting some debug code into RateScheduler.tick():

    /**
     * Called by all intervals with the particular rate.
     * @param rate The rate of the interval that called.
     */
    tick(rate) {
        if (!this.map.has(rate)) {
            return;
        }
        console.log("size " + this.map.get(rate).callbacks.length);
        this.map.get(rate).callbacks.forEach((cb) => cb[0]());
    }

And noticed that this is always increasing as soon as you turn the radio knob, or do any other actions like switching the vhf frequency index.

So looks like for some reason the cleanup code:

this.map.forEach((value) => {
    value.callbacks = value.callbacks.filter((cb) => cb !== callback);
});

doesn't seem to work as designed.

(I also noticed that we constantly create new StatefulSimVar objects whenever you turn the knob, but @Benjozork mentioned that this would be WAI. If that's the case, then cb !== callback won't work because StatefulSimVar.refreshCallback will be another object for every StatefulSimVar object I believe.)

theomessin commented 3 years ago

Ok I looked at this some by inserting some debug code into RateScheduler.tick():
    /**
     * Called by all intervals with the particular rate.
     * @param rate The rate of the interval that called.
     */
    tick(rate) {
        if (!this.map.has(rate)) {
            return;
        }
        console.log("size " + this.map.get(rate).callbacks.length);
        this.map.get(rate).callbacks.forEach((cb) => cb[0]());
    }
And noticed that this is always increasing as soon as you turn the radio knob, or do any other actions like switching the vhf frequency index.

So looks like for some reason the cleanup code:
this.map.forEach((value) => {
    value.callbacks = value.callbacks.filter((cb) => cb !== callback);
});
doesn't seem to work as designed.

(I also noticed that we constantly create new StatefulSimVar objects whenever you turn the knob, but @Benjozork mentioned that this would be WAI. If that's the case, then cb !== callback won't work because StatefulSimVar.refreshCallback will be another object for every StatefulSimVar object I believe.)

This is indeed the issue, I'm writing a bugfix at the moment. Amazing work finding this 🥳

Saschl commented 3 years ago

Just FYI to support this: https://discord.com/channels/738864299392630914/738864300818432023/807298347961417778

I could reproduce this quite early in flight (~30 min) so maybe we’re onto something here :)

Also I got some coherent draw issues while adding more StatefulSimVars. If it helps I’m glad :) Good luck!

Edit: I was obviously not getting the whole issue, I'm happy to see this :) (If anyone is interested in the very similar (ugly) "code" I created while investigating this to test whether the callbacks are going to increase more and more.

if (this.map.has(rate)) {
      for (let index = 0; index < 100; index++) {
                this.map.get(rate).callbacks.push(callback);
      }
      console.log(this.map.get(rate).callbacks.length);
      return;
};

theomessin commented 3 years ago

@Saschl, it's unfortunate that we didn't listen to you. Your message could've been used to fix this issue a lot sooner. However, just to be clear, JoJo sent proof via Discord which clearly identified the issue and made me get on fixing it right away. Your message got buried under a shitload of other messages which I read hours after they were sent. Part of the reason your message got "ignored" was simply poor timing 😞

Now, had you sent a more fleshed out report, even a screenshot of your attached code showing that the length of the callbacks array increases to infinity, I'd like to believe we would've listened. Looking at this from another perspective, however, if you knew what the issue was you could've submitted a pull request, such as #3358.

Now, all that said, this is not a blame game. It just so happens that this is the way this particular situation unfolded. I'm sure there's lessons learned for all of us, including myself as an individual, as well as the FBW Development Team. Hopefully we'll all take something from this and be better next time.

Saschl commented 3 years ago

I'm sorry for all the hassle, it's not my style actually. But all you say is right, I mean there's no one to blame and in the end the desired goal was achieved which is the most important part. I can not and will not blame anyone for my own insecurness, If I would have been more confident I would have cried it out loud :D Again, I'm sorry if my statements sounded somewhat childish and jealous. That was not my intention.

BritishAvgeek commented 3 years ago

What you linked is no longer an issue after recent optimisations. The current problem is caused by something else that was added recently.

Thanks, I wasn't sure so put it in the QA chat but then had it suggested to put it here... Didn't sound like it was linked but I don't know about this stuff 😂 so figured by putting it here it would at least be seen by one of you guys. Cheers!

sidnov commented 3 years ago

Fix looking good!🎉

flybywiresim / aircraft

[BUG] CoherentGTDraw gets very high after long flight #3302

Hold up!

Please do a clean install of commit aff960bf74a0a806cb56ae8a14d5990a6181dff9

Now do a clean install of pull request #3355 (eee44d1bc44e368f763d2f2f7dde660bb1065df1)