Aviation Lights *may* be involved on a weird bug report on Forum

[Lisias]

Fellow Kerbonaut exospaceman reported on Forum:

It's been 3 days since this bug started to occur on the game and I can't seem to get rid of it, If you can help me out I would appreciate it.

https://www.youtube.com/watch?v=yVVvBJniEwI

User wasn't able to switch scenes to Tracking Station, unless by returning to Space Center and launching a craft.

• KSP.log
• Player.log

I'm puzzled, and so asked the user to start to rip off add'ons in order to see if we find who was triggering the problem. And what wasn't my surprised when they answered Aviation Lights!! o.O

I'm not seeing how this could happen, but an evidence is an evidence. So I opened this issue to investigate the problem.

[Lisias]

So… That's my current working theory:

Recently, I replaced a dumb if(){} else if (){} else{} sequence on the PartModule's Update with this:

        public void Start()
        {
			if (HighLogic.LoadedSceneIsEditor)      this.CurrentUpdate = this.UpdateOnEditor;
			else if (HighLogic.LoadedSceneIsFlight) this.CurrentUpdate = this.UpdateOnFlight;
			else                                    this.CurrentUpdate = this.UpdateDummy;

and later:

        /// <summary>
        /// Check to update lights.
        /// </summary>
        public void Update() => this.CurrentUpdate();

A chained if sequence were replaced by a call to a delegator - boy, I call this a win for the performance guys.

HOWEVER this code relies that the PartModule is being Stopped and Started as specified by Unity's Life Cycle, as well in the known KSP's behaviour of packing (putting on rails) crafts when they are not in the Flight (of Editor) scene.

If by any reason this is not happening, then I may be calling the wrong this.CurrentUpdate() for the current Scene, and if by some reason the unavoidable Exception is being swallowed in an empty try…catch somewhere, well, we would have the current thread being killed and so this would explain the user's related misbehaviour.

So commit df04eb8 added some DEBUG boiler plate to detect if I'm calling the wrong this.CurrentUpdate() for the current scene.

[Lisias]

Tested the thing on KSP 1.4.3.

[LOG 23:55:47.156] [AviationLights] ERROR: I'm LoadedSceneIsFlight but the current scene is TRACKSTATION at error:0

KSP.log

https://www.youtube.com/watch?v=wJSZqSfloEE

However, this only happened once and not an awful amount of time, as one should expect. So what's happening is that the Scene is being switched before the PartModule is deactivated and destroyed!!

DAMN!!!

[Lisias]

Yep, it's happening too on 1.12.5

[LOG 00:46:29.915] [HighLogic]: =========================== Scene Change : From FLIGHT to TRACKSTATION (Async) =================
[LOG 00:46:30.122] [AviationLights] ERROR: I'm LoadedSceneIsFlight but the current scene is TRACKSTATION at error:0

However, this is also being logged only once, what means that the PartModule is being destroyed on Scene change.

Additionally, double checking the code it only depends of the this.vessel and it's own internal data (and it's own GameObject) to be alive, what obviously is still true at this point because I didn't logged any problem.

BUT… Depending in how things work inside KSP, it's possible that some thread could had destroyed the GameObject before the PartModule is destroyed due the "hybrid" CPU used by the user (that P-Core and E-Core stung from Intel).

It's a looooooong shot, but right now it's the only plausible explanation I could pull from my ass.

[Lisias]

I installed Kopernicus on the rig, but nothing changes from my side. But I found some interesting exceptions from it:

[ERR 01:02:55.948] Exception handling event onNewGameLevelLoadRequestWasSanctionedAndActioned in class RuntimeUtility:System.NullReferenceException: Object reference not set to an instance of an object
  at Kopernicus.RuntimeUtility.RuntimeUtility.PatchTimeOfDayAnimation () [0x00034] in <acd1e686455e4778bfe0f3575737e247>:0
  at Kopernicus.RuntimeUtility.RuntimeUtility.OnLevelLoaded (GameScenes scene) [0x0000a] in <acd1e686455e4778bfe0f3575737e247>:0

  at Kopernicus.RuntimeUtility.RuntimeUtility.<Awake>b__10_1 (GameScenes s) [0x00000] in <acd1e686455e4778bfe0f3575737e247>:0
  at EventData`1[T].Fire (T data) [0x000b0] in <106570632fc343a784fad39e75e877bf>:0

[EXC 01:02:55.952] NullReferenceException: Object reference not set to an instance of an object
        Kopernicus.RuntimeUtility.RuntimeUtility.PatchTimeOfDayAnimation () (at <acd1e686455e4778bfe0f3575737e247>:0)
        Kopernicus.RuntimeUtility.RuntimeUtility.OnLevelLoaded (GameScenes scene) (at <acd1e686455e4778bfe0f3575737e247>:0)
        Kopernicus.RuntimeUtility.RuntimeUtility.<Awake>b__10_1 (GameScenes s) (at <acd1e686455e4778bfe0f3575737e247>:0)
        EventData`1[T].Fire (T data) (at <106570632fc343a784fad39e75e877bf>:0)
        UnityEngine.DebugLogHandler:LogException(Exception, Object)
        KSPe.Util.Log.UnityLogDecorator:UnityEngine.ILogHandler.LogException(Exception, Object)
        ModuleManager.UnityLogHandle.InterceptLogHandler:LogException(Exception, Object)
        UnityEngine.Debug:LogException(Exception)
        EventData`1:Fire(GameScenes)
        <FireLoadedEvent>d__46:MoveNext()
        UnityEngine.SetupCoroutine:InvokeMoveNext(IEnumerator, IntPtr)
[LOG 01:02:55.973] [ScenarioTypes]: List Created 24 scenario types loaded from 45 loaded assemblies.

This Exception DO NOT happens on the user's rig.

This can be completely unrelated (and probably it is), but I'm blind and deaf, shooting in the dark hoping that something screams in the process...

[Lisias]

Well, out of desperation, I tried the commit 94357f3 . The ERROR entry mentioned some posts above is no more, what means that I effectively prevented the wrong UpdateThingy from running on the current scene.

It's absolute unsure at this time if this will do any good on the field, but at least the damned entry log was supressed so at least i can guarantee I'm not contributing to the problem neither.

let's see what the user will say about.

evidence of success: KSP.log (no ERRORs from Aviation Lights)

[Lisias]

Oukey, feedback time. My little stunt paid off!! :)

Downloaded the new Aviation lights game bug is no where to be seen even in a new sandbox

I think the bug appears or doesn't appear sometimes

And I think the user is right! See next post.

[Lisias]

The user have a i7-12700F (pretty decent), and this thing have two kinds of "cores" inside: 8 cores for Performance, and 4 cores for "Economy". The E-Cores are slower than the P-Cores, but KSP was coded on a time where every single Core inside your CPU was the same, so KSP is just using whatever is idle at the moment without caring about the differences.

So, suddenly, KSP is getting some internal threads running "out of the pace" related to some others (depending in which Core the threads is running at the moment).

So, as you add more and more add'ons, the KSP internal loops start to get fatter and fatter, and if some one of these fat internal loop ends up running on a E-Core, some things start to happen out of the pace compared to the loops that runs on the P-Cores (it's the reason I hate how Unity handles threads, and KSP handles concurrency - had these guys did the job properly, we would not be suffering this problem now).

By getting a bigger processor, you will have twice the E-Cores - what essentially doubles the chances of things going south (because you will have twice the number of threads running on slower cores). Believe it or not, the better is the processor your have, the worst is the problem for you.

"Vai dormir com um barulho desses…" as we say around here… (something like "Go figure it out…").

Going back to Aviation Lights, what I think it happened is that as that fat loops start to run on the E-Core, a critical code of AL became too much out of sync with the rest of the loops, and then something bad started to happen. What I did was to prevent that critical code from running outside the intended Scene by brute force (something that ideally I should not care, because KSP would kill the PartModule before the new Scene starts to kill old things), what apparently prevents AL from being directly hit by this problem I described.

About the problem being intermittent, perhaps only a few specific worker threads of KSP plays havoc when running on a E-Core, and so every time you startup KSP, we get a Russian Roulette about the subject.

Unfortunately, AL is only one of the possible targets of the problem - others will surely suffer the same.

[Lisias]

Closing this and proceeding with releasing Aviation Lights 4.2.1.1 as RELEASE.