ScrapYard (et all) is being screwed by a Race Condition those origin is still unknown

[Lisias]

As the tittle says. On certain circumstances still to be really understood, SYD is causing the following lines to be logged on KSP.log:

[LOG 18:03:19.170] [VesselMover] INFO: [Move Launch Controller]: Hiding Editor GUI
[LOG 18:03:19.190] [UIMasterController]: ShowUI
[ERR 18:03:19.423] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294516170

[ERR 18:03:19.423] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294516170

[ERR 18:03:19.423] [FlowGraph]: Graph already contains item! Part MK1Fuselage with id 4294501704

[ERR 18:03:19.423] [FlowGraph]: Graph already contains item! Part MK1Fuselage with id 4294501704

[ERR 18:03:19.423] [FlowGraph]: Graph already contains item! Part liquidEngine2.v2 with id 4294490830

[ERR 18:03:19.424] [FlowGraph]: Graph already contains item! Part liquidEngine2.v2 with id 4294490830

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294516170

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294516170

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part MK1Fuselage with id 4294501704

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part MK1Fuselage with id 4294501704

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part liquidEngine2.v2 with id 4294490830

[ERR 18:03:19.570] [FlowGraph]: Graph already contains item! Part liquidEngine2.v2 with id 4294490830

[LOG 18:04:37.356] [AsteroidSpawner]: New object found near Kerbin: Ast. VHY-392!

It's interesting to note that:

• For some people, this crap is being triggered all the time no matter what
• For me, early month when I first gave this a try but idiotically didn't saved any evidences, I spent 2 OR 3 DAYS trying to reproduce the thing without success, after initially being able to reproduce it using a savegame from the user that reported the problem.
  • This is important to note, because until firing up that savegame, I wasn't able to reproduce the problem no matter what.
• Today, on a new savegame on a minimal KSP 1.12.5 installation, I was able to consistently reproduce this problem to a point I started to think that I had completely screwed up my early month test sessions by hallucinating due sleep deprivement - what would be a hell of a hallucination because I diagnosed #66 exactly while probing SYD.
• Also today, after starting a new Career savegame on the same rig (after a game reboot), suddenly the damned thing started to behave correctly and consistently behaved correctly until I closed the game!

I'm finally near the cause of the problem now. What I need to do is to find a way to screw up things again, then realise what I did to "get it fixed", and once I consistently establish a Modus Operandi, go doing Regression Tests on previous KSP versions to see what I pull from that fishing expedition. Exactly as I did on #66.

Evidences:

• test-scrapyard.zip : KSP 1.12.5 Sandbox savegame where the problem was consistently being reproduced.
• test-scrapyard-career.zip : KSP 1.12.5 Career savegame where I managed to get the problem fixed (or masked?) somehow.
  • KSP.log.zip : KSP.log of this test session.
    • Things appears to start to behave at [LOG 21:32:48.736], but there's an Exception on SYD when going from Flight to Scene once. But it happened only once, apparently.
    • A full analysis if this log is still work in progress.

EDIT

There's another possible trigger for the problem! Instead of a mysterious event in need to happen in order to make SYD to behave, it may be that a mysterious event is happening and screwing up SYD in the process.

[Lisias]

New test session for KSP 1.4.1:

• KSP.log.zip
• test-scrap.zip

Interesting findings, I will update this issue later as I have confirmation for some working theories.

"Those who cannot remember the past are condemned to repeat it." - George Santayana.

[Lisias]

Test session for KSP 1.12.5

• KSP.log.zip
• test-scrapyeard-persistenId.zip

Working theories confirmed. More interesting findings to be disclose later, at my convenience.

"Dude, what a fscking mess…" — Myself.

EDIT: the persistentId is less persistent than it should be. ScrapYard is not the problem, it's a victim fighting the problem.

[Lisias]

Commit https://github.com/net-lisias-ksp/KSP-Recall/commit/d7147fdbb4ebc2f3196c1b1c5db85281efaae8bb adds the Diagnosing PartModule used on the tests I will describe below.

[Lisias]

This is the results of a Test Session where the above mentioned PartModule was used to monitor the part.persistentId attribute on KSP 1.4.1.

This is what was done:

1. Install the TestPersistentId stunt I created on KSP-Recall
2. Fire up KSP 1.4.1
3. Create a new Career game called test-scrapyead (delete if already exists). Open it
4. Go to editor, create a simple craft with 1 mk1pid and 1 Flea SolidBooster
5. Save it as Untitled Space Craft
6. Launch it
7. Recover it
8. Go to Editor
9. Load the craft again
10. Launch it again
11. Recover it again
12. Goto step 8 a couple times, I think (forgot how many times I did it!!)
13. Go to Editor
14. Load the Craft again
15. Launch it again
16. Revert to Launch
17. Quit the game.

• KSP.log.zip
• test-scrapyard.zip

[Lisias]

This is (more or less) the same, but when executed on KSP 1.12.5. It's interesting to note that besides finally being able to reproduce the problem, it took me some more attempts.

• KSP.log.zip
• test-scrapyard.zip

[Lisias]

Interesting excerpts from the 1.4.1 log:

[LOG 15:55:42.110] [ModuleManager] INFO: Applying update __LOCAL/KSP-Recall/TestPersistentId/@PART[*]:FINAL to Squad/Parts/Command/mk1pod/mk1Pod.cfg/PART[mk1pod]

[LOG 15:56:25.366] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF26DC has persistentId=2174048135 at before OnAwake
[LOG 15:56:25.366] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF26DC has persistentId=2174048135 at after OnAwake
[LOG 15:56:25.366] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF26DC has persistentId=2174048135 at before OnLoad
[LOG 15:56:25.367] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF26DC has persistentId=2174048135 at after OnLoad
[LOG 15:56:25.381] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFF26B8 has persistentId=2174048135 at before OnAwake
[LOG 15:56:25.381] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFF26B8 has persistentId=2174048135 at after OnAwake
[LOG 15:56:25.383] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):0 has persistentId=2174048135 at OnDestroy

[LOG 15:56:25.402] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone) Drag Rendering Clone:FFFF2640 has persistentId=2174048135 at before OnAwake
[LOG 15:56:25.402] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone) Drag Rendering Clone:FFFF2640 has persistentId=2174048135 at after OnAwake
[LOG 15:56:25.477] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone) Drag Rendering Clone:FFFF2640 has persistentId=2174048135 at OnDestroy
[LOG 16:31:20.448] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC6AC6 has persistentId=2174048135 at before OnAwake
[LOG 16:31:20.448] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC6AC6 has persistentId=2174048135 at after OnAwake
[LOG 16:31:20.460] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at before OnSave
[LOG 16:31:20.460] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at after OnSave
[LOG 16:31:20.489] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at before OnStart
[LOG 16:31:20.489] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at after OnStart
[LOG 16:31:23.922] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at before OnSave
[LOG 16:31:23.922] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at after OnSave
[LOG 16:31:25.403] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at before OnSave
[LOG 16:31:25.403] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at after OnSave
[LOG 16:31:27.251] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at before OnSave
[LOG 16:31:27.251] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at after OnSave
[LOG 16:31:27.536] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC6AC6 has persistentId=2174048135 at OnDestroy

[LOG 16:31:29.092] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC4B62 has persistentId=2174048135 at before OnAwake
[LOG 16:31:29.093] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC4B62 has persistentId=2174048135 at after OnAwake
[LOG 16:31:29.096] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnLoad
[LOG 16:31:29.096] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnLoad
[LOG 16:31:31.143] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnSave
[LOG 16:31:31.181] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnSave
[LOG 16:31:31.227] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnSave
[LOG 16:31:31.227] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnSave
[LOG 16:31:33.507] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnStart
[LOG 16:31:33.693] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnStart
[LOG 16:31:35.305] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnSave
[LOG 16:31:35.305] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnSave
[LOG 16:31:37.451] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at before OnSave
[LOG 16:31:37.451] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at after OnSave
[LOG 16:31:37.759] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC4B62 has persistentId=2174048135 at OnDestroy

[LOG 16:31:46.619] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFBC676 has persistentId=2174048135 at before OnAwake
[LOG 16:31:46.619] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFBC676 has persistentId=2174048135 at after OnAwake
[LOG 16:31:46.621] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at before OnLoad
[LOG 16:31:46.621] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at after OnLoad
[LOG 16:31:46.686] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at before OnSave
[LOG 16:31:46.686] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at after OnSave
[LOG 16:31:46.688] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at before OnStart
[LOG 16:31:46.688] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at after OnStart
[LOG 16:31:52.589] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFBADBA has persistentId=3230181786 at before OnAwake
[LOG 16:31:52.589] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFBADBA has persistentId=3230181786 at after OnAwake
[LOG 16:31:52.591] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at before OnLoad
[LOG 16:31:52.591] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at after OnLoad
[LOG 16:31:52.601] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at before OnSave
[LOG 16:31:52.601] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at after OnSave
[LOG 16:31:52.603] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at before OnStart
[LOG 16:31:52.603] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at after OnStart
[LOG 16:31:52.605] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBC676 has persistentId=2174048135 at OnDestroy

[LOG 16:31:53.798] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at before OnSave
[LOG 16:31:53.798] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at after OnSave
[LOG 16:31:54.074] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFBADBA has persistentId=3660509158 at OnDestroy

[LOG 16:31:55.547] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFB930A has persistentId=2174048135 at before OnAwake
[LOG 16:31:55.547] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFB930A has persistentId=2174048135 at after OnAwake
[LOG 16:31:55.549] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnLoad
[LOG 16:31:55.549] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnLoad
[LOG 16:31:57.534] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnSave
[LOG 16:31:57.534] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnSave
[LOG 16:31:57.538] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnSave
[LOG 16:31:57.538] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnSave
[LOG 16:31:59.645] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnStart
[LOG 16:31:59.646] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnStart
[LOG 16:32:00.519] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnSave
[LOG 16:32:00.519] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnSave
[LOG 16:32:02.565] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at before OnSave
[LOG 16:32:02.565] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at after OnSave
[LOG 16:32:02.876] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB930A has persistentId=3660509158 at OnDestroy

[LOG 16:32:11.995] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFB0E02 has persistentId=2174048135 at before OnAwake
[LOG 16:32:11.995] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFB0E02 has persistentId=2174048135 at after OnAwake
[LOG 16:32:11.996] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at before OnLoad
[LOG 16:32:11.996] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at after OnLoad
[LOG 16:32:12.005] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at before OnSave
[LOG 16:32:12.005] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at after OnSave
[LOG 16:32:12.007] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at before OnStart
[LOG 16:32:12.007] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at after OnStart
[LOG 16:32:17.297] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFAF5A6 has persistentId=2174048135 at before OnAwake
[LOG 16:32:17.297] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFAF5A6 has persistentId=2174048135 at after OnAwake
[LOG 16:32:17.299] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at before OnLoad
[LOG 16:32:17.299] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at after OnLoad
[LOG 16:32:17.308] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at before OnSave
[LOG 16:32:17.308] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at after OnSave
[LOG 16:32:17.309] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at before OnStart
[LOG 16:32:17.309] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at after OnStart
[LOG 16:32:17.311] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFB0E02 has persistentId=3660509158 at OnDestroy
[LOG 16:32:18.565] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at before OnSave
[LOG 16:32:18.565] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at after OnSave
[LOG 16:32:18.820] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFAF5A6 has persistentId=2174048135 at OnDestroy

[LOG 16:32:20.228] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFADADE has persistentId=2174048135 at before OnAwake
[LOG 16:32:20.228] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFADADE has persistentId=2174048135 at after OnAwake
[LOG 16:32:20.229] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at before OnLoad
[LOG 16:32:20.229] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at after OnLoad
[LOG 16:32:22.206] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at before OnSave
[LOG 16:32:22.206] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at after OnSave
[LOG 16:32:22.210] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at before OnSave
[LOG 16:32:22.210] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at after OnSave
[LOG 16:32:24.300] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at before OnStart
[LOG 16:32:24.300] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at after OnStart
[LOG 16:32:25.185] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at before OnSave
[LOG 16:32:25.185] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at after OnSave
[LOG 16:32:34.074] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFADADE has persistentId=2174048135 at OnDestroy

[LOG 16:32:34.498] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFA79B4 has persistentId=2174048135 at before OnAwake
[LOG 16:32:34.498] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFA79B4 has persistentId=2174048135 at after OnAwake
[LOG 16:32:34.515] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFA794E has persistentId=2174048135 at before OnLoad
[LOG 16:32:34.515] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFA794E has persistentId=2174048135 at after OnLoad
[LOG 16:32:34.516] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFA79B4 has persistentId=2174048135 at OnDestroy

[LOG 16:32:36.305] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod (Untitled Space Craft):FFFA794E has persistentId=2174048135 at before OnStart
[LOG 16:32:36.305] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod (Untitled Space Craft):FFFA794E has persistentId=2174048135 at after OnStart
[LOG 16:32:36.882] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod (Untitled Space Craft):FFFA794E has persistentId=2174048135 at before OnSave
[LOG 16:32:36.882] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod (Untitled Space Craft):FFFA794E has persistentId=2174048135 at after OnSave

Please note the following timestamps:

• [LOG 16:31:46.619] to [LOG 16:31:52.605]
• [LOG 16:32:11.995] to [LOG 16:32:18.820]

[Lisias]

Interesting excerpts from the 1.12.5 log (I took more time to reproduce the problem on this one)

[LOG 18:00:11.831] [ModuleManager] INFO: Applying update __LOCAL/KSP-Recall/TestPersistentId/@PART[*]:FINAL to Squad/Parts/Command/mk1pod_v2/mk1Pod_v2.cfg/PART[mk1pod_v2]
[LOG 18:03:49.993] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFFE99E0 has persistentId=0 at before OnAwake
[LOG 18:03:49.993] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFFE99E0 has persistentId=0 at after OnAwake
[LOG 18:03:49.996] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFFE99E0 has persistentId=0 at before OnLoad
[LOG 18:03:49.996] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFFE99E0 has persistentId=0 at after OnLoad
[LOG 18:03:50.003] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFFE99A6 has persistentId=0 at before OnAwake
[LOG 18:03:50.003] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFFE99A6 has persistentId=0 at after OnAwake
[LOG 18:03:50.004] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):0 has persistentId=0 at OnDestroy

[LOG 18:03:50.014] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone) Drag Rendering Clone:FFFE9942 has persistentId=0 at before OnAwake
[LOG 18:03:50.014] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone) Drag Rendering Clone:FFFE9942 has persistentId=0 at after OnAwake
[LOG 18:03:50.082] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone) Drag Rendering Clone:FFFE9942 has persistentId=0 at OnDestroy

[LOG 18:11:43.023] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF8FC56 has persistentId=0 at before OnAwake
[LOG 18:11:43.023] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF8FC56 has persistentId=0 at after OnAwake
[LOG 18:11:43.041] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at before OnSave
[LOG 18:11:43.041] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at after OnSave
[LOG 18:11:43.346] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at before OnStart
[LOG 18:11:43.346] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at after OnStart
[LOG 18:11:46.322] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at before OnSave
[LOG 18:11:46.322] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at after OnSave
[LOG 18:11:48.646] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at before OnSave
[LOG 18:11:48.646] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at after OnSave
[LOG 18:11:49.601] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at before OnSave
[LOG 18:11:49.602] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at after OnSave
[LOG 18:11:50.065] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8FC56 has persistentId=3820334531 at OnDestroy

[LOG 18:11:53.226] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF8D29E has persistentId=0 at before OnAwake
[LOG 18:11:53.226] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF8D29E has persistentId=0 at after OnAwake
[LOG 18:11:53.231] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnLoad
[LOG 18:11:53.231] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnLoad
[LOG 18:11:54.909] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnSave
[LOG 18:11:54.909] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnSave
[LOG 18:11:54.943] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnSave
[LOG 18:11:54.943] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnSave
[LOG 18:12:09.371] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnStart
[LOG 18:12:09.371] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnStart
[LOG 18:12:10.563] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnSave
[LOG 18:12:10.563] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnSave
[LOG 18:13:31.783] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at before OnSave
[LOG 18:13:31.783] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at after OnSave
[LOG 18:13:32.288] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF8D29E has persistentId=3820334531 at OnDestroy

[LOG 18:13:45.500] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF7F41A has persistentId=0 at before OnAwake
[LOG 18:13:45.500] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF7F41A has persistentId=0 at after OnAwake
[LOG 18:13:45.560] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at before OnLoad
[LOG 18:13:45.561] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at after OnLoad
[LOG 18:13:45.569] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at before OnSave
[LOG 18:13:45.569] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at after OnSave
[LOG 18:13:45.585] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at before OnStart
[LOG 18:13:45.585] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at after OnStart
[LOG 18:13:47.974] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at before OnSave
[LOG 18:13:47.974] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at after OnSave
[LOG 18:13:48.485] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7F41A has persistentId=3820334531 at OnDestroy

[LOG 18:13:51.003] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF7B2BA has persistentId=0 at before OnAwake
[LOG 18:13:51.003] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF7B2BA has persistentId=0 at after OnAwake
[LOG 18:13:51.005] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnLoad
[LOG 18:13:51.005] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnLoad
[LOG 18:13:52.549] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnSave
[LOG 18:13:52.549] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnSave
[LOG 18:13:52.554] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnSave
[LOG 18:13:52.554] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnSave
[LOG 18:13:54.459] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnStart
[LOG 18:13:54.459] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnStart
[LOG 18:13:54.873] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnSave
[LOG 18:13:54.873] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnSave
[LOG 18:14:11.441] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at before OnSave
[LOG 18:14:11.441] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at after OnSave
[LOG 18:14:11.907] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF7B2BA has persistentId=3820334531 at OnDestroy

[LOG 18:15:07.779] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF6D4AE has persistentId=0 at before OnAwake
[LOG 18:15:07.779] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF6D4AE has persistentId=0 at after OnAwake
[LOG 18:15:07.781] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at before OnLoad
[LOG 18:15:07.781] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at after OnLoad
[LOG 18:15:07.789] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at before OnSave
[LOG 18:15:07.789] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at after OnSave
[LOG 18:15:07.803] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at before OnStart
[LOG 18:15:07.803] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at after OnStart
[LOG 18:15:09.939] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at before OnSave
[LOG 18:15:09.939] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at after OnSave
[LOG 18:15:10.404] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6D4AE has persistentId=3820334531 at OnDestroy

[LOG 18:15:12.825] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF6934E has persistentId=0 at before OnAwake
[LOG 18:15:12.825] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF6934E has persistentId=0 at after OnAwake
[LOG 18:15:12.826] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at before OnLoad
[LOG 18:15:12.826] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at after OnLoad
[LOG 18:15:14.329] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at before OnSave
[LOG 18:15:14.329] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at after OnSave
[LOG 18:15:14.334] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at before OnSave
[LOG 18:15:14.334] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at after OnSave
[LOG 18:15:16.199] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at before OnStart
[LOG 18:15:16.199] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at after OnStart
[LOG 18:15:16.605] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at before OnSave
[LOG 18:15:16.605] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at after OnSave
[LOG 18:15:31.098] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF6934E has persistentId=3820334531 at OnDestroy

[LOG 18:15:31.936] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF5F51A has persistentId=0 at before OnAwake
[LOG 18:15:31.936] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF5F51A has persistentId=0 at after OnAwake
[LOG 18:15:31.953] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF5F4C0 has persistentId=3820334531 at before OnLoad
[LOG 18:15:31.953] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF5F4C0 has persistentId=3820334531 at after OnLoad
[LOG 18:15:31.953] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF5F51A has persistentId=0 at OnDestroy

[LOG 18:15:33.475] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5F4C0 has persistentId=3820334531 at before OnStart
[LOG 18:15:33.475] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5F4C0 has persistentId=3820334531 at after OnStart
[LOG 18:15:33.876] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5F4C0 has persistentId=3820334531 at before OnSave
[LOG 18:15:33.876] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5F4C0 has persistentId=3820334531 at after OnSave
[LOG 18:16:04.126] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5F4C0 has persistentId=3820334531 at OnDestroy
[LOG 18:16:05.018] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF58684 has persistentId=0 at before OnAwake
[LOG 18:16:05.018] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF58684 has persistentId=0 at after OnAwake
[LOG 18:16:05.032] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF5862A has persistentId=3820334531 at before OnLoad
[LOG 18:16:05.032] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF5862A has persistentId=3820334531 at after OnLoad
[LOG 18:16:05.032] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF58684 has persistentId=0 at OnDestroy

[LOG 18:16:06.495] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at before OnStart
[LOG 18:16:06.495] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at after OnStart
[LOG 18:16:06.881] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at before OnSave
[LOG 18:16:06.881] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at after OnSave
[LOG 18:16:18.611] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at before OnSave
[LOG 18:16:18.611] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at after OnSave
[LOG 18:16:19.048] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2 (Untitled Space Craft):FFF5862A has persistentId=3820334531 at OnDestroy
[LOG 18:16:31.937] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF4D552 has persistentId=0 at before OnAwake
[LOG 18:16:31.937] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF4D552 has persistentId=0 at after OnAwake
[LOG 18:16:31.939] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at before OnLoad
[LOG 18:16:31.939] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at after OnLoad
[LOG 18:16:31.947] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at before OnSave
[LOG 18:16:31.947] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at after OnSave
[LOG 18:16:31.962] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at before OnStart
[LOG 18:16:31.962] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at after OnStart
[LOG 18:16:37.256] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF49CE0 has persistentId=0 at before OnAwake
[LOG 18:16:37.256] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF49CE0 has persistentId=0 at after OnAwake
[LOG 18:16:37.258] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=3820334531 at before OnLoad
[LOG 18:16:37.258] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=3820334531 at after OnLoad
[LOG 18:16:37.269] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at before OnSave
[LOG 18:16:37.269] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at after OnSave
[LOG 18:16:37.285] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at before OnStart
[LOG 18:16:37.285] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at after OnStart
[LOG 18:16:37.289] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF4D552 has persistentId=3820334531 at OnDestroy
[LOG 18:16:39.072] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at before OnSave
[LOG 18:16:39.072] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at after OnSave
[LOG 18:16:39.490] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF49CE0 has persistentId=2703135624 at OnDestroy

[LOG 18:16:42.235] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF47CD0 has persistentId=0 at before OnAwake
[LOG 18:16:42.235] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF47CD0 has persistentId=0 at after OnAwake
[LOG 18:16:42.236] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnLoad
[LOG 18:16:42.236] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnLoad
[LOG 18:16:43.700] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnSave
[LOG 18:16:43.700] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnSave
[LOG 18:16:43.733] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnSave
[LOG 18:16:43.733] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnSave
[LOG 18:16:45.582] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnStart
[LOG 18:16:45.582] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnStart
[LOG 18:16:45.982] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnSave
[LOG 18:16:45.982] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnSave
[LOG 18:16:48.934] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at before OnSave
[LOG 18:16:48.934] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at after OnSave
[LOG 18:16:49.369] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF47CD0 has persistentId=2703135624 at OnDestroy

[LOG 18:17:01.882] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF39EF0 has persistentId=0 at before OnAwake
[LOG 18:17:01.882] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF39EF0 has persistentId=0 at after OnAwake
[LOG 18:17:01.894] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at before OnLoad
[LOG 18:17:01.894] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at after OnLoad
[LOG 18:17:01.902] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at before OnSave
[LOG 18:17:01.902] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at after OnSave
[LOG 18:17:01.917] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at before OnStart
[LOG 18:17:01.917] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at after OnStart
[LOG 18:17:06.759] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF3667E has persistentId=0 at before OnAwake
[LOG 18:17:06.759] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF3667E has persistentId=0 at after OnAwake
[LOG 18:17:06.761] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at before OnLoad
[LOG 18:17:06.761] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at after OnLoad
[LOG 18:17:06.769] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at before OnSave
[LOG 18:17:06.769] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at after OnSave
[LOG 18:17:06.782] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at before OnStart
[LOG 18:17:06.782] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at after OnStart
[LOG 18:17:06.785] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF39EF0 has persistentId=2703135624 at OnDestroy

[LOG 18:17:08.125] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at before OnSave
[LOG 18:17:08.126] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at after OnSave
[LOG 18:17:08.561] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3667E has persistentId=3820334531 at OnDestroy

[LOG 18:17:11.346] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF3466E has persistentId=0 at before OnAwake
[LOG 18:17:11.346] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2(Clone):FFF3466E has persistentId=0 at after OnAwake
[LOG 18:17:11.348] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnLoad
[LOG 18:17:11.348] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnLoad
[LOG 18:17:12.830] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnSave
[LOG 18:17:12.830] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnSave
[LOG 18:17:12.842] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnSave
[LOG 18:17:12.843] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnSave
[LOG 18:17:14.861] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnStart
[LOG 18:17:14.861] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnStart
[LOG 18:17:15.298] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnSave
[LOG 18:17:15.298] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnSave
[LOG 18:22:18.219] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnSave
[LOG 18:22:18.219] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnSave
[LOG 18:27:18.910] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at before OnSave
[LOG 18:27:18.910] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at after OnSave
[LOG 18:30:19.367] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod.v2:FFF3466E has persistentId=3820334531 at OnDestroy

Please note the following timestamps:

• [LOG 18:16:06.495] to [LOG 18:16:39.490]
• [LOG 18:17:01.882] to [LOG 18:17:06.785]

[Lisias]

What I detected until this moment:

• On KSP 1.4.1, persistentId was already initialised on OnAwake.
  • On KSP 1.12.5, it was still on 0! This surely screwed up some people in the wild
• On both logs, you will find blocks where multiple instances of the same part were being instantiated at the same time, where the second one ends up earning a new persistenceId.
  • the cid (the value used on the [FlowGraph] appears to be the same - this is something I need to write code to check.
  • Every single part of the Craft behaves similarly .
  • My best guess is a race condition when instantiating the Craft into the current Scene, leading to it being done twice concomitantly.
  • The new persistentId is saved into the craft file if the user hits the "Save" button when it happens in Editor, otherwise the craft file will keep the original values.
  • And this really screws up ScrapYard, as it uses the persistentId written on the craft file!

I'm currently working on a deterministic way to create that "instantiation clashes" at will.

[Lisias]

There's also an ongoing discussion happening on Forum here.

The reader should be able to deduce the reason I locked up this issue by visiting this link. :)

[Lisias]

This is not a support anymore, I found a bug on KSP itself. This makes it an enhancement for KSP-Recall.

How I will do it, I will see after I managed to detect what in hell is triggering to crafts to be instantiated in memory at the same time.

[Lisias]

Ah, yes!! I almost forgot to explain this! :)

Okey, the commit https://github.com/zer0Kerbal/ScrapYard/commit/0576f776a6477da56f53f6e9db2aa5978d37d47b was a step back, besides trying to be a step ahead by using the KSP's API when possible. It's sad that this very commit started the sad sequences of events that leaded this one one line being added:

https://github.com/zer0Kerbal/ScrapYard/blob/0576f776a6477da56f53f6e9db2aa5978d37d47b/ScrapYard/Modules/ModuleSYPartTracker.cs#L27

However… And let's make things clear on this, the logs above proves that on ideal conditions (i.e., the persistentId being consistently initialised and kept), that line besides being less than ideal, should also be harmless if KSP's didn't introduced the bug (but without the bug, would not had existed a reason to write it at first place).

Without the bug, on KSP 1.4.1 that line would just write back something that was already there. And on KSP 1.12.5, if the code would be run on OnAwake, that line would be needed because somewhere in the mean time KSP started to failing to provide the part.persistentId already initialised as it was happening on KSP 1.4.1.

So, and again, on ideal conditions, that unhappy line should be harmless. ScrapYard is causing trouble because KSP is "changing the persistentId" and the ScrapYard way to cope with the problem become itself a problem on a later KSP version.

[Lisias]

For the sake of fairness, it was stated that the persistentId was meant to change.

This is fact, a fait accompli and not subject to arguing. This renders the ScrapYard code in need to be changed, that's final.

I'm having a hard time trying to swallow this pill (it makes no sense in my mind), but things are how they are and I'm redoing the tests with this in mind - but my initial code (assuming it's not buggy itself) is suggesting that the onPartPersistentIdChanged is not being issued during the "Event" - and so we still have a bug on KSP to cope with.

If things are happening as they should, I must be able to intercept the onPartPersistentIdChanged thingy while that Race Conditions I detected is happening. But until this moment, on the only time I managed to reproduce the misbehaviour (crap…), it wasn't - still checking if I screwed up the test code.

[Lisias]

The GameEvents.onPartPersistentIdChanged are not being called, and it's not a bug. The only place in which it would be necessary is using FlightGlobals.CheckPartpersistentId(0, part, false, true) (note the 0), and this appears to prevent the event - that makes sense, there's no "from" to handle.

note to myself: there's a lot of information on Forum, move the relevant bits to this issue.

[Lisias]

Oukey, new Exploratory Tests trying to understand how things really works under's KSP's bonnet.

I reinstrumented the TestPersistentId PartModule, and then executed the following session:

1. Installed the reinstrumented PartModule (obviously)
2. Deleted the previous savegame called test-persistenid
3. Fired up KSP
4. Created a new Career game called test-persistentid
5. Created again that Untitled Space Craft using the MK1 pod and the Flea. Saved it.
6. Launched the thing into the LaunchPad
7. Gone back to KSC, then entered the editor
8. The previously launched craft was automaticaly loaded. I loaded it again.
9. Quit the game, and gathered the evidences below.

• KSP.log.zip
• test-persistentid.zip

[Lisias]

Now follows an except of the previous KSP.log, with some interesting new information:

[LOG 18:39:19.795] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF38AA has persistentId=91659911 at OnAwake. The cid is 2480147.
[LOG 18:39:19.795] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF38AA has persistentId=91659911 at OnLoad. The cid is 2480147.
[LOG 18:39:19.811] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFF3886 has persistentId=91659911 at OnAwake. The cid is 2480147.
[LOG 18:39:19.813] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):0 has persistentId=91659911 at OnDestroy. The cid is 2480147.
[LOG 18:41:32.819] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFCCE60 has persistentId=91659911 at OnAwake. The cid is 2480147.
[LOG 18:41:32.831] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:32.860] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnStart. The cid is 2480147.
[LOG 18:41:36.459] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:37.522] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:38.440] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:38.718] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE60 has persistentId=91659911 at OnDestroy. The cid is 2480147.

[LOG 18:41:40.247] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFCACD6 has persistentId=91659911 at OnAwake. The cid is 2480147.
[LOG 18:41:40.250] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnLoad. The cid is 2480147.
[LOG 18:41:40.260] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnInitialize. The cid is 2480147.
[LOG 18:41:42.294] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:42.306] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnInitialize. The cid is 2480147.
[LOG 18:41:42.314] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:44.491] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnStart. The cid is 2480147.
[LOG 18:41:46.242] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:48.517] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnInitialize. The cid is 2480147.
[LOG 18:41:50.871] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:51.167] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCACD6 has persistentId=91659911 at OnDestroy. The cid is 2480147.

[LOG 18:41:57.873] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC2988 has persistentId=91659911 at OnAwake. The cid is 2480147.
[LOG 18:41:57.875] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC2988 has persistentId=91659911 at OnLoad. The cid is 2480147.
[LOG 18:41:57.884] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC2988 has persistentId=91659911 at OnInitialize. The cid is 2480147.
[LOG 18:41:57.885] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC2988 has persistentId=91659911 at OnSave. The cid is 2480147.
[LOG 18:41:57.886] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC2988 has persistentId=91659911 at OnStart. The cid is 2480147.
[LOG 18:42:45.857] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFC10FC has persistentId=2366749665 at OnAwake. The cid is 2480147.
[LOG 18:42:45.861] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC10FC has persistentId=1795537535 at OnLoad. The cid is 2480147.
[LOG 18:42:45.871] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC10FC has persistentId=1795537535 at OnInitialize. The cid is 2480147.
[LOG 18:42:45.871] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC10FC has persistentId=1795537535 at OnSave. The cid is 2480147.
[LOG 18:42:45.874] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC10FC has persistentId=1795537535 at OnStart. The cid is 2480147.
[LOG 18:42:45.876] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFC2988 has persistentId=91659911 at OnDestroy. The cid is 2480147.

Nothing special, the persistentId is changing as expected. Whoever, there's on more thing on log and this thing is not changing ever, the cid or Part.ClassID attribute. You can get it from:

Craft file:

PART
{
        part = mk1pod_4294757984.      // the cid is the number after underscode
        partName = Part
        persistentId = 91659911
        pos = 0,15,0
        attPos = 0,0,0
        attPos0 = 0,15,0
        rot = 0,0,0,1
        attRot = 0,0,0,1
        attRot0 = 0,0,0,1
        mir = 1,1,1

SFS file:

                        PART
                        {
                                name = mk1pod
                                cid = 4294757984      // <——— HERE!!!
                                uid = 4222129561
                                mid = 2128778212
                                persistentId = 91659911
                                launchID = 1

And why I'm showing you all of this? Because the ID being logged on the LogSpam IS THE CID, not the persistentId!!

The ordeal was misdiagnosed on Forum. The persistentId is not the problem, the ~classID~ CraftId is!!

Additionally, it's a good idea to figure out what's uid and mid too, as Kraken knows what else would be relying on these ones.

[Lisias]

This is the analysis of a previous KSP.log where the LogSpam was triggered:

ksp.log

    [WRN 01:54:35.863] [ScrapYard] value != part.persistentId)!! 1935682175 != Part.mk1pod.v2.1768470123
    [WRN 01:54:35.863] [ScrapYard] value != part.persistentId)!! 701172246 != Part.solidBooster.sm.v2.979641015
    [LOG 01:54:35.864] [ScrapYard] Adding build (parts)
    [LOG 01:54:35.865] [ScrapYard] mk1pod.v2 has been used 1/1/0 (T/N/I) times.
    [LOG 01:54:35.866] [ScrapYard] solidBooster.sm.v2 has been used 1/1/0 (T/N/I) times.
    [LOG 01:54:35.866] [ScrapYard] mk1pod.v2 has been used in 1/1/0 (T/N/I) builds.
    [LOG 01:54:35.866] [ScrapYard] solidBooster.sm.v2 has been used in 1/1/0 (T/N/I) builds.
    [LOG 01:54:35.869] Flight State Captured
    [LOG 01:54:35.870] Saving Achievements Tree...
    [LOG 01:54:35.871] [MessageSystem] Save Messages
    [LOG 01:54:35.921] Game State Saved as persistent
    [LOG 01:54:36.605] [Untitled Space Craft]: ground contact! - error. Moving Vessel  down -0.207m
    [LOG 01:54:36.605] Unpacking Untitled Space Craft
    [LOG 01:54:36.610] [VesselMover] INFO: [Move Launch Controller]: Hiding Editor GUI
    [LOG 01:54:36.612] [UIMasterController]: ShowUI
    [ERR 01:54:36.714] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294401494

    [ERR 01:54:36.714] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294401494

    [ERR 01:54:36.714] [FlowGraph]: Graph already contains item! Part solidBooster.sm.v2 with id 4294400912

    [ERR 01:54:36.714] [FlowGraph]: Graph already contains item! Part solidBooster.sm.v2 with id 4294400912

    [ERR 01:54:36.776] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294401494

    [ERR 01:54:36.776] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294401494

    [ERR 01:54:36.776] [FlowGraph]: Graph already contains item! Part solidBooster.sm.v2 with id 4294400912

    [ERR 01:54:36.776] [FlowGraph]: Graph already contains item! Part solidBooster.sm.v2 with id 4294400912

Now the craft file:

    PART
    {
            part = mk1pod.v2_4294401494
            partName = Part
            persistentId = 1768470123

And now the SFS file:

    PART
    {
        name = mk1pod.v2
        cid = 4294401494
        uid = 3987364613
        mid = 1624790515
        persistentId = 1935682175
        launchID = 1

Now observe the following copy&pastes:

    [ERR 01:54:36.714] [FlowGraph]: Graph already contains item! Part mk1pod.v2 with id 4294401494
—
            part = mk1pod.v2_4294401494
—
        name = mk1pod.v2
        cid = 4294401494

You see? The problem is not, and never were the persistenId. The problem is the cid!!!!

[Lisias]

The Part.ClassID attribute is not properly documented on the KSP's API, unfortunately.

[edit]: what doesn't matter, because cid is CraftId. And some documentation is available.

[Lisias]

Other than misunderstanding CraftId with ClassId, things appears to be on the right direction.

I reloaded that last KSP 1.4.1. savegame used, with an Untitled Space Craft already on the LaunchPad, opened the Editor and loaded the craft file - two times in a row, but the second one after 5 minutes to make things easier do detect on the log.

Now we have two copies of the same Craft on memory, one on the LaunchPad and another on the Editor:

[LOG 15:45:10.259] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF38AA has persistentId=438584920 at OnAwake. The ClassID is 2480147 and the CraftId (cid) is 4294916266.
[LOG 15:45:10.259] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFF38AA has persistentId=438584920 at OnLoad. The ClassID is 2480147 and the CraftId (cid) is 4294916266.
[LOG 15:45:10.274] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFF3886 has persistentId=438584920 at OnAwake. The ClassID is 2480147 and the CraftId (cid) is 4294916230.
[LOG 15:45:10.276] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):0 has persistentId=438584920 at OnDestroy. The ClassID is 2480147 and the CraftId (cid) is 4294916230.
[LOG 15:46:51.738] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFCCE8E has persistentId=438584920 at OnAwake. The ClassID is 2480147 and the CraftId (cid) is 4294758030.
[LOG 15:46:51.742] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE8E has persistentId=91659911 at OnLoad. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:46:51.762] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE8E has persistentId=91659911 at OnInitialize. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:46:51.768] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE8E has persistentId=91659911 at OnSave. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:46:51.791] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE8E has persistentId=91659911 at OnStart. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:56.513] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod(Clone):FFFCCA78 has persistentId=438584920 at OnAwake. The ClassID is 2480147 and the CraftId (cid) is 4294756984.
[LOG 15:53:56.516] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnLoad. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:56.524] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnInitialize. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:56.525] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnSave. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:56.527] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnStart. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:56.529] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCE8E has persistentId=91659911 at OnDestroy. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:59.005] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnSave. The ClassID is 2480147 and the CraftId (cid) is 4294757984.
[LOG 15:53:59.388] [KSP-Recall.Test.PersistentId] INFO: Part mk1pod:FFFCCA78 has persistentId=631267469 at OnDestroy. The ClassID is 2480147 and the CraftId (cid) is 4294757984.

The first batch of mk1pod log ([LOG 15:45:10.259]) happened on the Part Compile phase, while loading KSP, and have the InstanceID= FFFF38AA . By some reason, the part is instantiated again as (Clone), now with InstanceId= FFFF3886.

At [LOG 15:46:51.738] we have another instantiation, now with InstanceID= FFFCCE8E . And then yet a new one, with InstanceID= FFFCCA78 at [LOG 15:53:56.513]. These two are the craft file being loaded on Editor.

It's interesting to note that for a brief time, the parts FFFCCE8E and FFFCCA78 coexist in memory, with FFFCCE8E being destroyed only after FFFCCA78 is Started! These two parts have the same CraftId but different persistentId.

• KSP.log.zip
• test-persistentid.zip

Note: I did not entered the Flight Scene on this session, so the packet craft on the LaunchPad was never unpacked (ie., made "alive" in memory).

[Lisias]

I did a new test on KSP 1.12.5 and the LogSpam just ceased to happen under my nose.

I will save the assets here now to avoid loosing them, but I will come back later to further discuss the matter. Right now, I'm just pissed off about the matter.

• https://github.com/net-lisias-kspw/ScrapYard/tree/issues/ksp-recall/67
• https://github.com/net-lisias-ksp/ksp-recall/tree/dev
• KSP 1.12.5:
  • KSP.log.zip
  • test-scrapyard.zip
• KSP 1.4.1:
  • KSP.log.zip
  • test-scrapyard.zip

M.O.:

1. Compile and install the HEAD of the branches above on the target KSP
2. Fire the damned thing
3. Create a new savegame called test-scrapyard (delete any previously existent one)
4. Create a craft called Untitled Space Craft on VAB. Save it and then launch it into Launch Pad
5. Go back to KSC, leaving the craft on the Launch Pad
6. Enter VAB
7. Load again the Untitled Space Craft.
8. Do it again just for the lulz
9. Exit the game session
10. Close KSP

On KSP 1.4.1, the LogSpam didn't happened a single time. On KSP 1.12.5, it happened once, and then just vanished into thin air.