KSP Recall

KSP Recall

345k Downloads

KSP 1.9.x resets resources to prefab while cloning parts

ferox96 opened this issue · 27 comments

commented

Tried updating to 1.9 since most mods behave reasonably on updates nowadays. Began noticing some parts drifting each time I loaded my craft (either in flight or VAB). Seems any parts that have been tweaked start to wander when loading.

Also noticed that when copying a part that had been altered, the new part retained the correct appearance and size, but was given the default values for the original part. (FL-T400 tank scaled to 3.75 has almost 2k LOx, copy has 360). Tweakscale seems to be applying itself at the wrong time or somehow affecting the "assembly order" upon load in. The most interesting fact is that if I load a craft and a part wanders, then reload the same craft without saving, the part will have wandered farther than before.

I am using other mods such as mechjeb, but afaik none would be interfering with TS or craft loading. Hope I have been of some service, TS has been very nice to me, would like to return the favor.

commented

I confirmed the reset resource size behaviour on a almost vanilla KSP instalment. I will further check it again tomorrow, but I'm pretty convinced that KSP 1.9 and TweaskScale is enough to trigger the problem.

The wandering, however, I could not reproduce. I need a craft file where this happens and the KSP.log of your instalment for inspection. The MM logs and cache can help too.

commented

Terrible news. The order of the events are the same for both 1.8.x (where things work fine) as well for 1.9 (where they don't).

The cloning of the part is the problem. On a blind guess, it's something inside KSP that changed places, or some code that was added - this behaviour is similar to something I had detected on 1.6 IIRC, and that I described on Forum here.

The resource may be being applied again from the prefab, overwriting the current data, as I described before.

If course this is speculation by now.

KSP 1.8.1
[LOG 04:59:34.307] [TweakScale] TRACE: UpdateCrewManifest 4294526132
[LOG 04:59:35.644] [TweakScale] TRACE: OnAwake miniFuselage(Clone)
[LOG 04:59:35.644] [TweakScale] TRACE: Setup for miniFuselage(Clone)
[LOG 04:59:35.644] [TweakScale] TRACE: SetupFromConfig for miniFuselage(Clone)
[LOG 04:59:35.647] [TweakScale] TRACE: OnStart miniFuselage
[LOG 04:59:37.074] miniFuselage added to ship - part count: 3
[LOG 04:59:37.075] [TweakScale] TRACE: OnSave miniFuselage
[LOG 04:59:37.075] [TweakScale] TRACE: OnSave miniFuselage
[LOG 04:59:40.707] [TweakScale] TRACE: OnSave miniFuselage
[LOG 04:59:40.708] [TweakScale] TRACE: OnSave miniFuselage

KSP 1.9
[LOG 05:07:14.392] [TweakScale] TRACE: UpdateCrewManifest 4294508168
[LOG 05:07:16.211] [TweakScale] TRACE: OnAwake miniFuselage(Clone)
[LOG 05:07:16.211] [TweakScale] TRACE: Setup for miniFuselage(Clone)
[LOG 05:07:16.211] [TweakScale] TRACE: SetupFromConfig for miniFuselage(Clone)
[LOG 05:07:16.212] [TweakScale] TRACE: OnStart miniFuselage
[LOG 05:07:17.543] miniFuselage added to ship - part count: 3
[LOG 05:07:17.543] [TweakScale] TRACE: OnSave miniFuselage
[LOG 05:07:17.543] [TweakScale] TRACE: OnSave miniFuselage
[LOG 05:07:19.914] [TweakScale] TRACE: OnSave miniFuselage
[LOG 05:07:19.915] [TweakScale] TRACE: OnSave miniFuselage
commented

Oh man how lucky I feel to be the 96th issue reported :)

commented

That's my current hypothesis:

When TweakScale receives its OnAwake, there's no guarantee that every other Module on that part had received its OnAwake too.

Until now, by plain luck as it appears, TweakScale were being "awaked" after the Resources module, and so things were working. On KSP 1.9, things are not deterministic as it used to be - and so, TweakScale can now be awakened before the Resources.

And so, the OnAwake of that Resource would undo the TweakScale initialisation.

I moved some initialisation code to OnStart, and got this on the log:

[LOG 06:49:56.407] [TweakScale] TRACE: UpdateCrewManifest 4294605864
[LOG 06:49:57.816] [TweakScale] TRACE: OnAwake miniFuselage(Clone)
[LOG 06:49:57.822] [TweakScale] TRACE: OnStart miniFuselage
[LOG 06:49:57.822] [TweakScale] TRACE: Setup for miniFuselage
[LOG 06:49:57.822] [TweakScale] TRACE: SetupFromConfig for miniFuselage
[LOG 06:49:58.593] miniFuselage added to ship - part count: 3
[LOG 06:49:58.594] [TweakScale] TRACE: OnSave miniFuselage
[LOG 06:49:58.594] [TweakScale] TRACE: OnSave miniFuselage
[LOG 06:50:08.495] [TweakScale] TRACE: OnSave miniFuselage
[LOG 06:50:08.495] [TweakScale] TRACE: OnSave miniFuselage

What's evidence that the change is working the way I intended. But the problem persisted.

This change didn't affected KSP 1.8.1 neither 1.7.3.

commented

So, just to see what happens, I shoved the initialisation code on unity's Start event hander.

[LOG 07:54:17.940] [TweakScale] TRACE: UpdateCrewManifest 4294605662
[LOG 07:54:19.062] [TweakScale] TRACE: OnAwake miniFuselage(Clone)
[LOG 07:54:19.065] [TweakScale] TRACE: OnStart miniFuselage
[EXC 07:54:19.073] NullReferenceException: Object reference not set to an instance of an object
        TweakScale.TweakScale.GetModuleMass (System.Single defaultMass, ModifierStagingSituation situation) (at <78cbc2c60a9640a18098d01398b6d0a5>:0)
        Part.ModulesOnStart () (at <58d65a64fbb0404d9f5cd2fab581f784>:0)
        Part+<Start>d__297.MoveNext () (at <58d65a64fbb0404d9f5cd2fab581f784>:0)
        UnityEngine.SetupCoroutine.InvokeMoveNext (System.Collections.IEnumerator enumerator, System.IntPtr returnValueAddress) (at <7d9ec060e791409ab3eb85
[LOG 07:54:19.073] [TweakScale] TRACE: Start miniFuselage
[LOG 07:54:19.073] [TweakScale] TRACE: Setup for miniFuselage
[LOG 07:54:19.073] [TweakScale] TRACE: SetupFromConfig for miniFuselage
[LOG 07:54:19.873] miniFuselage added to ship - part count: 3
[LOG 07:54:19.874] [TweakScale] TRACE: OnSave miniFuselage
[LOG 07:54:19.875] [TweakScale] TRACE: OnSave miniFuselage

Well... This settles the matter. Things need to be initialised on OnStart, and everything should be set up before the unity's Start.

commented

From the Issue Report:

Also noticed that when copying a part that had been altered, the new part retained the correct appearance and size, but was given the default values for the original part. (FL-T400 tank scaled to 3.75 has almost 2k LOx, copy has 360). TweakScale seems to be applying itself at the wrong time or somehow affecting the "assembly order" upon load in

Unfortunately, nope. When you Alt-Click a part, you clone the part. TweakScale doesn't needs to apply itself again, as the new part's data is cloned from the original. The Resources being reset to the prefab's appears to hint that something is overwriting the Resources after the part is cloned.

The interesting part is that a combination of third-parties Add'Ons, when installed together TweakScale, had "fixed" the problem! So it appears to be something that TweakScale should be done on KSP 1.9, and currently it's not - and once someone else does it, TweakScale works as expected.

The current line of research had proven itself fruitless.

From now, I will nail down exactly what Add'On from that bunch I realised by accident that fixed the problem, and then will see what it does and try to mimic it on TweakScale.

commented

OW, GREAT!!!! (só que não).

By installing some other Add'Ons, the problem vanishes!!! 👯

So we have a race condition. :P

On the other hand, I have a hunch about the problem now...

commented

WorkArounds

  • Do not cloning parts (ie, avoiding using Alt+Click to duplicate existing parts).
    • Frankly, this is a pain the SAS. I use this a lot.
    • Mirroring also does some cloning. Nasty.
  • Use SubAssemblies to replace cloning
    • Instead of using Alt+Click, just click on the whole subtree and drop it on the SubAssemblies zone.
    • Then click on the subassembly you want and drop it on the craft
  • Use Scale Chaining.
    • Just build everything without scaling them yet.
    • Then hit CTRL+K . This will enable Scale Chaining.
      • screenshot8
    • Scale the root part of the intended subpart to be scaled:
      • Everything will scale all-right, including mirrored parts.
      • screenshot9
    • Probably the second best option.
  • Instal Interstellar Fuel Switch. Yeah, I'm serious.
    • By just installing this thing, the problem goes away.
    • The reason is currently RiP (Research in Progress)
      • Currently I'm speculating that IFS managed to undo Squad's stunt, or by plain luck managed to be missed by it.
    • Perhaps other Fuel Switch would do the trick too?
commented

Evidences of Misbehaviours:

  • Reproducing the problem:
    • Drop a root part on the Editor: screenshot3
    • Drop a small tank:
      screenshot4
    • Scale it, and then Alt-Click on it to clone it:
      screenshot5
    • Attach the cloned part: screenshot6
      • note the second tank correctly sized and placed, but with the resource amount reset to the prefab!
commented

I was wrong. See post below.


Ha! Gotcha!

From the 1.9 readme, I got this:

  • Fix Issue for mods when copying parts that had modified resource lists.

By an incredible lucky strike, I have an evidence of how Squad implemented it, and I'm pretty confident that this is the cause of the problem!

See the screenshot below:
screenshot11

The lateral tanks were cloned from the central ones (both scaled correctly using CTRL-K) and placed in mirror, what fired up cloning 4 tanks.

The orange mark depicts an intermediary state of one part, where the max amount is still scaled, but the current amount was already mangled down to the prefab values. I got incredibly lucky on managing this screenshot, I didn't managed to reproduce this again!

This suggests that the Squad's code broke the Part Life Cycle, making changes on the part after it was initialised. Worst, they decided to do it on a uncontrolled thread fired concurrently, creating incredible opportunities for a nice race condition on the system.

This IS NOT a TweakScale bug. This is a new bug introduced on KSP 1.9, resulted from a badly implemented workaround.

commented

That's a lot to take in for me, but I mostly understand. Do you have any information on parts wandering around when loading crafts? I have a lander craft with 4 tanks radially mounted to a central tank and pushed in partway so about half of the radial tanks is visible. Each time I load the craft, the parts move a small amount outward. The oddest behavior is that even if I don't save over the craft, but simply reload it repeatedly, the part continues to move further each time. From my [very limited] understanding of coding, i'm not sure how the engine is storing the changes it makes. If I load, load, load the craft 5-6 times, the radial tanks pop up floating several meters away from contact with the central tank. Odd behavior that is very likely also squads fault.

Thank you so much for all this info and effort you have put forth, and the very timely response. Will give IFS a shot and report if all my issues disappear also.

commented

Ouch. There's something else borking heavily on your instalment. Don't care on reproducing the issue, just delete the MM cache, fire up KSP and close it on the Main Menu.

Then pack KSP.log, MM cache and logs on a zip file and post here. You have more than one problem on your rig, I think that by solving this last one, at least the wandering will go away.

commented

Well so far IFS seems to solve both issues for me. I believe it does this by basically jumping in front of TS and delaying TS long enough for everything you mentioned to work itself out. Have not tested IFS functionality since i'm not really sure what it does yet. Noticed I could change fuel types on a tank, so assume it is working also.

I will take the steps you said and post shortly, I've been itching to launch this thing. Had just finished putting it together when the update dropped. Do you still want the craft file? It's a Falcon 9 remake with a custom lander/return vessel inside the fairing. Had to piece each stage together by sampling different parts TS'd to proper size. Procedural parts was wonderful for building a measuring stick complete with color coding.

commented

OK update. Have 2 craft files to share. Rocketman 1 and Rocketman 2. Rocketman 1 is working fine, can clone parts properly, doesn't wander on load. Rocketman 2 is built off of Rocketman 1, very much like the Falcon Heavy, with 2 center core's mounted radially. However, Rocketman 2 suffers from the wandering issue again. I've custom tweaked a few engine parameters so they may not perform the same in your game. Vectors don't quite match Merlin-1D, and Wolfhound doesn't either.

Here are the craft files, along with the log from my last session in a zip file.

1-9 Compatibility issues.zip

Where do I find the MM cache to delete/copy and is KSP the only log you need?

commented

That's a lot to take in for me, but I mostly understand.

Good. :)

I battling two fronts here - one, the bugs, and the other the historical misconception that TweakScale is a trouble maker (what sometimes I wonder it's the reason the previous maintainer got fed up and waved TS).

This is not about finger pointing, however. It's about avoiding being finger pointed at the same time we detect not only the problem, but the reason the problem happened - so we can try to do something to prevent it to happen again.

"Closing an issue" is not enough. We need to fix the problem at the same time preventing new issues to be opened due the stunt. :)

Do you have any information on parts wandering around when loading crafts? I have a lander craft with 4 tanks radially mounted to a central tank and pushed in partway so about half of the radial tanks is visible. Each time I load the craft, the parts move a small amount outward. The oddest behavior is that even if I don't save over the craft, but simply reload it repeatedly, the part continues to move further each time.

I could not reproduce this specific issue yet. And I tried. It may be related to an unholy interaction between a third-party Add'On with TweakScale while being hit by this problem, but can be the other way around, that third party Add'On can be borking due this stunt, and so TweakScale borks too.

What you describes happens when TweakScale borks while calculating the Attach Points new position due the scaling. I never managed to force this behaviour as you described, but I once managed to make something somewhat more interesting: the attached parts just "flew away" into infinity - the event handler was crashing before hinting it has finished, and so something else was calling it again.

Obviously, it can be the same misbehaviour but twisted by a new KSP version - who knows? But in a way or another, apparently this happens due an interaction with something else, I never got this by using TweakScale only on a vanilla KSP instalment.

From my [very limited] understanding of coding, i'm not sure how the engine is storing the changes it makes. If I load, load, load the craft 5-6 times, the radial tanks pop up floating several meters away from contact with the central tank. Odd behavior that is very likely also squads fault.

It smells like an event handler borking on the KSP guts, leaving things unfinished. So the next Load ends up loading the craft over a dirty buffer, what can be an explanation for the behaviour. As you load and load again, you do it over the remains of the last load, and so the misbehaviours piles up.

I'm guessing, however. I need more info in order to better speculate about.

Thank you so much for all this info and effort you have put forth, and the very timely response. Will give IFS a shot and report if all my issues disappear also.

Welcome! In a way or another, could you attach here the craft file and the KSP.log of the session where you reproduce the thing? It can be something else, and it's not unusual that KSP.log can give me a hint or two, as well the craft file.

commented

I'll have to run that test again, my last play thru wasn't very long. Upon reviewing the KSP.log I did notice an interesting series of lines. I will save it incase you need more context, but after I check IFS as a fix on my end, I will recreate the problems without IFS installed. Here's some lines from my KSP.log file:

[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on TD-25 Decoupler. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on Probodobodyne OKTO2. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T100 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T100 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-TX220 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-TX440 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T100 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T100 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on TD-06 Decoupler. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on Probodobodyne OKTO2. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on Advanced Inline Stabilizer. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T800 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T800 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T800 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T400 Fuel Tank. Set to center of part.
[WRN 17:41:38.025] [AttachNode]: Unable to invert surface node on FL-T400 Fuel Tank. Set to center of part.
[ERR 17:42:11.935] Cannot find module 'TweakScale' (-1948744604)

[ERR 17:42:11.935] Module TweakScale threw during OnStart: System.NullReferenceException: Object reference not set to an instance of an object
at TweakScale.TweakScale.Setup () [0x0004b] in <6abb476517a84d89b511b2077e7c6791>:0
at TweakScale.TweakScale.OnStart (PartModule+StartState state) [0x00028] in <6abb476517a84d89b511b2077e7c6791>:0
at Part.ModulesOnStart () [0x00120] in <3e135473f56a45478d738eb041ebd6cb>:0

commented

I was wrong on the race condition. See this post for more info.

https://forum.kerbalspaceprogram.com/index.php?/topic/179030-141/&do=findComment&comment=3747989

commented

This is a problem on KSP 1.9, still present on KSP 1.9.1 - so I edited the Title to reflect it.

commented

IFS managed to be imune to this problem by completely overruling stock behaviour. It essentially reimplements the resource list, and overwrite any change made by KSP itself by:

  1. It completely overrules anything the stock behaviour does by keeping an internal resource list for every part it works on and applying them as the last step of his initialisation steps.
  2. It handles TweakScale scaling events, and updates its internal resource list
  3. So the scaling is applied on the Step 1

The name of the thing is 'AssignResourcesToPart', on file KSP-Interstellar-Extended⁩/FuelSwitch⁩/InterstellarFuelSwitch.cs.

Screen Shot 2020-02-28 at 12 07 27

Also on Forum.

IFS github: https://github.com/sswelm/KSP-Interstellar-Extended/tree/master/FuelSwitch

commented

Ok i'll get those MM items zipped right away.

Gotta say again that i'm so appreciative of the effort you have put into this issue. I know i'm not alone in the struggle but I don't take it for granted.

....upon entering my GameData folder, I am noticing I do not have .configcache or .configSHA. Is this an issue?

commented

Hi, @ferox96

Where do I find the MM cache to delete/copy and is KSP the only log you need?

Its on the GameData, on the same place ModuleManager.dll is:

999_Scale_Redist.dll
ModuleManager.4.0.2.dll
ModuleManager.ConfigCache
ModuleManager.ConfigSHA
ModuleManager.Physics
ModuleManager.TechTree
ModuleManagerLicense.md

Don't bother picking - shove everything that it's not a DLL or a MD file and starts with ModuleManager on a zip file and call it a day. :)

commented

And yes, I have a confirmation about my thesis on the "Wandering Part" problem. I'm seeing a lot of problems similar to this excerpt:

[LOG 22:22:26.876] [TweakScale] WARNING: No valid member found for surfaceArea in ModuleAeroSurface for airbrake1
[LOG 22:22:26.882] [TweakScale] WARNING: No valid member found for surfaceArea in ModuleAeroSurface for airbrake1
[LOG 22:22:26.887] [TweakScale] WARNING: No valid member found for surfaceArea in ModuleAeroSurface for airbrake1
[LOG 22:22:26.892] [TweakScale] WARNING: No valid member found for surfaceArea in ModuleAeroSurface for airbrake1
[LOG 22:22:26.897] [TweakScale] WARNING: No valid member found for mass in TweakScale for radialDecoupler2
[LOG 22:22:26.902] [TweakScale] WARNING: No valid member found for mass in TweakScale for radialDecoupler2
[ERR 22:22:26.952] Cannot find module 'TweakScale' (-1948744604)

[ERR 22:22:26.952] Module TweakScale threw during OnLoad: System.NullReferenceException: Object reference not set to an instance of an object
  at TweakScale.TweakScale.Setup () [0x0004b] in <6abb476517a84d89b511b2077e7c6791>:0
  at TweakScale.TweakScale.OnLoad (ConfigNode node) [0x00042] in <6abb476517a84d89b511b2077e7c6791>:0
  at PartModule.Load (ConfigNode node) [0x001ab] in <3e135473f56a45478d738eb041ebd6cb>:0
commented

Again about the Wandering Effect. I tested RocketMan2 on KSP 1.9 with KRE only.

When I loaded it. I told KSP to ignore the unknown modules, added a part (to trigger the dirty flag), saved it.

Then I loaded it, and the boosters are "gone". I launched it, and then I reverted to Vehicle Assembly. And now the boosters are back to their place, besides mirrored (as the part I added on top of it is now on the other side!).

I think we have a symmetry problem too, running side by side with TweakScale being borked by KSP. We could have, additionally, something on the attachment points.

I will further pursue this later - now I have to cook something that could fix this @#$@#$@%$ for everybody (and not just for TweakScale), ideally without the need of the Add'Ons having to be changed to interact to it.

commented

This issue was transfered to KSP-Recall, as this is where the problem will be handled.

commented

@ferox96 , I think you will want to keep an eye on issue #3 .

commented

This feature is working fine - apparently. :)

Closing it for publishing a new release.

commented

Gotta say again that i'm so appreciative of the effort you have put into this issue. I know i'm not alone in the struggle but I don't take it for granted.

Welcome! :)

....upon entering my GameData folder, I am noticing I do not have .configcache or .configSHA. Is this an issue?

Yes. It means that or you are risking your SAS using my Experimental MM fork :D , or you are using the Stock MM but there're errors on the patches, what prevents MM to built the cache.

This can be a reason for the wandering parts - what you describes happens when TweakScale is borking due a NRE in its guts what just happens by third-parties code injecting non-sense on the GameDatabase (or borking themselves when called by TweakScale when they implement the Scale_Redist interface) - and I just inadvertently (re)confirmed this while writing KSP Recall, by the way. :)

Right now, you need to ask for help on the MM thread - what historically ended up with the user coming back here, as they were not helpful. :P

But since today I'm busy with this new Recall stunt, may I ask you to ask for help there first? Sometimes someone helps, and if by the end of the day you still have the problem, ping me back here with the most recent copy of your KSL.Log and also the MM logs (I think they are in the <ksp_root>/Logs directory) and I will give it a look.