Refactor initializeVehicleForUPFG to fix bugs related to virtual stages

[Noiredd]

The vehicle definition (vehicle) is a static, user-input data structure unrelated to sequence, in which the user defines launch sequence events. In order to provide UPFG with complete information on the vehicle, changes that sequence events might introduce to the vehicle definition (such as an engine shutdown) must be accounted for. The old approach to updating vehicle was to iterate over sequence, check which stage will be running when an event is encountered, and split that stage into its version prior to the event, and a new "virtual" stage describing the vehicle status after it. Finally, acceleration limits would be accounted for after all the sequence-related changes.

This was a problem for several reasons that are discussed in detail in #47.

This PR replaces the old algorithm with a proper vehicle-centric approach. The new approach is to:

• iterate over stages,
• detect whether some vehicle-altering event happens during that stage,
• detect whether that stage has an acceleration limit to respect,
• handle whichever situation happens first: gLim switch or sequence event.

Additionally, in order to definitively catch all sequence bugs (like an event that just happens to end up between two stages, and thus escape the initialization routine), a small routine was added that goes over the sequence once more after the entire process, and checks whether some events were missed. All vehicle-altering events that initializeVehicleForUPFG takes into account are marked as "processed"; if some event did not receive that mark, it is a sign of trouble and the user will be messaged about it, and relevant data will be dumped to a file to allow analysis.

I've taken the new code for a few spins and it seems solid. @theLXMB if you want to try this yourself and tell me if it works for you or breaks under some scenarios, I'd greatly appreciate it.

Closes #47

[theLXMB]

Perfect, I'll run some tests with my oddball launchers, hopefully tomorrow ;)

[Noiredd]

Btw, about the throttle blip you mentioned - I've noticed this too, and it's still present here. I'll look into it, hopefully fix it in another commit under this PR. For now let's make sure the core change works well :)

[theLXMB]

So, sadly it took a week, but I have some results! So far, aside from that blip, for the most part all my launchers behave as they should. That one bizarre case I mentioned had nothing to do with PEGAS or a script error. One tank just randomly decided to become tri-propellant...

But here is the next oddity:

This launcher is basically the same as the one I showed you in #47. Only difference being, it has two boosters ("model number" 2145 instead of 0145). This doesn't make much of a difference to UPFG, as they're dropped way before activation or convergence. At that point it's only going faster at a higher altitude with a heavier payload. But the weird thing is, every script event is executed as it should, just not the fairing jettison. I have no idea why. There is no other event within 20 seconds either side (T+145). I checked and rechecked my staging. It still blips the throttle as expected, I then have to do it manually which prompts the second blip. But by that point PEGAS should never assume a sudden change in mass and therefore acceleration, or am I wrong?

[Noiredd]

Just so I understand correctly: you have a jettison type event in your sequence and PEGAS refuses to hit spacebar to execute it, and you have to do it manually? It's visible in the flight plan (T+145 Abwurf...) but nothing happens?

[theLXMB]

Correct, yes. The entire vehicle list is exactly the same for both launchers, sequence and controls obviously is different. For Seeotter-I 0145:

GLOBAL sequence IS LIST(
        LEXICON("time", -1.5, "type", "stage", "message", "Zuendung"),
        LEXICON("time", 0, "type", "stage", "message", "Start"),
        LEXICON("time", 155, "type", "jettison", "massLost", 2214, "message", "Abwurf Nutzlastverkleidung")
).  
GLOBAL controls IS LEXICON(
            "launchTimeAdvance", 150,
            "verticalAscentTime", 7,
            "pitchOverAngle", 5,
            "upfgActivation", 89
).

For Seeotter-I 2145:

GLOBAL sequence IS LIST(
        LEXICON("time", -1.5, "type", "stage", "message", "Zuendung"),
        LEXICON("time", 0, "type", "stage", "message", "Start"),
        LEXICON("time", 96, "type", "stage", "message", "Booster Abtrennung"),
        LEXICON("time", 145, "type", "jettison", "massLost", 2214, "message", "Abwurf Nutzlastverkleidung")
).  
GLOBAL controls IS LEXICON(
            "launchTimeAdvance", 150,
            "verticalAscentTime", 5,
            "pitchOverAngle", 10.2,
            "upfgActivation", 110
).

Booster separation (stage) is the only addition in sequence, fairing jettison ist supposed to happen ten seconds earlier and the ascent parameters in controls are bit more aggressive with upfgActivation 21 seconds later accounting for booster burn time.

At first I thought it might be connected to the procedural fairing being a deprecated part after a mod update but both rockets use it and changing to a non deprecated fairing did nothing. Sometimes I had MechJeb interfere with atmospheric flight, like for instance a supersonic plane controlled by Atmosphere Autopilot, when the Q limiter was falsely active. But that's also not it. The most basic thing I tried was to move the jettison to T+155 as in the 0145 variant, but to no avail. I'm at a total loss right now 🧐

[Noiredd]

Sadly, I am unable to reproduce this issue. I took the same vehicle I used to reproduce the gLim issue, attached a pair of GEM-60s to it (via Booster Mounting Kits, no idea if that's a vanilla part or from some mod) and changed the config to exactly what you posted above. It flew perfectly well.
I also tried scheduling the fairing jettison 10s earlier and later, i.e. at T+135, T+145 and T+153, the last one being 153 and not 155 because stage separation occurs around T+163.5 in my version so I didn't want to push too close to that event. In all cases the vehicle executed all steps as it should: boosters were dropped, UPFG converged, gLim kicked in, fairing was dropped, stages separated, orbit was reached (or would be, I didn't always bother to wait).

If this happens consistently, here's what I'd recommend you do.

1. Check if the file sequence_errors.log exists after a flight (it's created by initializeVehicleForUPFG if something goes wrong) and post its contents.
2. Insert this line: LOG sequence TO "sequence.log". right before activation of the active guidance loop in pegas.ks, e.g. here and post contents.
3. Insert the following code: LOG TIME:SECONDS to "events.log". LOG nextEventPointer TO "events.log". LOG event TO "events.log". into function eventHandler in pegas_events.ks, right after the highlighted line, and post the contents of this file after the flight.

Run a bug-afflicted mission and send all the debug files here; best would be to attach them to the post rather than pasting the content directly (they might get large).

[theLXMB]

I'm sorry it took a while, sadly life got in the way again. But I finally managed to do the logging: There is no sequence_errors.log. The other two where generated: sequence.log events.log

At first glance I'm not getting much out of it. At t+145 there are two events, the first is the attempted jettison and the second I presume is UPFG accounting for the mass lost during staging. Hence _upfgstage.

No idea if this actually means anything, the value for fpMessage changes a couple of times:

• t+110 is "STAGE: Seeotter-I Hauptstufe", as expected for activation of active guidance.
• t+125.31ish "Constant Acceleration mode", again as expected.
• t+145 "STAGE: Seeotter-I Hauptstufe" again at the "jettisoning" event. Not referencing the gLim mode. Is this just wording?

At t+170.07 the logs end with what PEGAS thinks is staging in the upper stage but in reality is fairing jettison. Supposed starting of the engine is the actual staging event and then obviously thrustWatchdog terminates the launch, as it looks like an engine failure. So there is no problem with "hitting the spacebar". It's just being skipped at t+145. Apart from the _prestage at t+143 there's still nothing 20s either side of the event. I am more confused than before 🤔

[Noiredd]

Thanks for following up on this with detailed logs.

I have to admit I'm baffled. Looking at the events.log, the "Abwurf Nutzlastverkleitung" jettison-type event is printed there. Which means eventHandler DID encounter this event. How come the LOG line you inserted works, and the STAGE command located mere 7 lines below doesn't?

I'd like you to confirm one other thing for me. If you fly this vehicle manually, does one hit of the spacebar stage the fairing? One way to make sure would be to launch it as normal, but then try to stage manually around T+130 (after const-acc mode trigger). Crucial question is: will it drop in one go, or will you have to hit again?

One common reason for STAGE not executing from kOS is when you have e.g. two STAGEs in rapid succession. Turns out staging takes one or more physics ticks to properly "process", so you can't stage again immediately after. But it doesn't look like it's the case here, as nothing of this sort is happening for the previous 50 seconds (1 second between stagings is sufficient).

What happens afterwards (the subsequent _upfgstage type event also scheduled at T+145) shouldn't matter either, as it's just the virtual stage activation for the "post-jettison" part of the original first stage (and it only sets some technical flags). It shouldn't matter because the flight is already screwed even before this triggers, i.e. the payload fairing wasn't dropped. If you want to be sure, I can look deeper but you'd have to provide the exact layout of the vehicle variable. Meaning you'd have to fly this again but also add LOG vehicle TO "vehicle.log". right after the LOG sequence bit. While I don't think this will be helpful, won't hurt to add this when flying that manual test I've mentioned above.

[theLXMB]

Ok, so this is getting weirder...

Simply sitting on the launch pad, having the fairings as the only thing in the first stage (the Staging Stack that is) and no PEGAS running, they simply detach in both variants (0145 and 2145) when pressing the space bar. As they should. Flying both rockets fully by hand, the 0145 drops them without issue but the 2145, I have to hit it twice. So presumably with PEGAS active, it does actually "hit the space bar", me then doing it manually is the second press. And so your suggestion worked; staging around t+130, nothing happened but at t+145 the fairings were jettisoned. Weirdly, if I simply remove the boosters in the VAB and change absolutely nothing else, effectively turning the 2145 into the 0145, then fly it by hand, it also works the first time... I am losing my mind here...

And the logs of course: events.log sequence.log vehicle.log

I'm still going to test the "removed boosters" variant with the proper 0145 boot script, as the 2145 simply pitches too early and aggressively for no boosters, almost immediately plunging into the Atlantic.

[Noiredd]

Sorry for getting back to it so late, real life interfered.

Your issue does seem to be caused by your vehicle config and/or mods. PEGAS does everything right - it's your vehicle that responds erroneously to a correct command. I'd love to help you with troubleshooting that, but sadly I've got enough debugging on my own plate right now.

Thank you very much for stress-testing this PR so hard though. Following your problem really helped ensure this is "production" ready. I'll merge as soon as I finish updating my install to 1.12.5 and kOS v1.14 and giving it a few extra test runs on my standard vehicles.

[theLXMB]

Hey, I'm sorry I also took so long to answer, same issue here...

Yes, I agree, this problem has nothing to do with PEGAS. Somehow the boosters mess up the staging. Maybe the integrated stack separators and parachutes have something to do with it, although it worked before and now doesn't... well, anyway this seems to be a problem of another mod. No worries with helping me on this, I sadly rarely get to play KSP right now. Hopefully I'll have more time in the coming months/year.

And I'm glad I could help in my limited capacity. I can't imagine launching any somewhat realistic rocket without PEGAS anymore and the more robust the code, the better ;)