Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Game stutters when vessel change state from landed to in flight or vice versa #3033

Closed
RCrockford opened this issue Jun 18, 2021 · 5 comments · Fixed by #3042
Closed

Game stutters when vessel change state from landed to in flight or vice versa #3033

RCrockford opened this issue Jun 18, 2021 · 5 comments · Fixed by #3042
Labels
Milestone

Comments

@RCrockford
Copy link
Contributor

When a vessel hits the ground or takes off there is a noticeable stutter as Principia takes or releases control of the vessel.

This can easily be seen by bouncing a vessel against the floor repeatedly (Physx will often do this for you).
There will be a noticeable pause on each bounce; switching hack gravity on will result in smooth frame rates suggesting that it is Principia causing the issue.

@eggrobin eggrobin added the bug label Jun 25, 2021
@eggrobin
Copy link
Member

Reproduced with a jumping Kerbal; journal attached.
JOURNAL.20210625-161301.zip

Sorry, something went wrong.

@eggrobin
Copy link
Member

eggrobin commented Jul 3, 2021

That journal is a bit annoying to replay (it is recorded at Gröbner, which uses an older setup of the dependencies), so the following traces are from a new journal at 412e338 (again simply jumping on the runway). Note that the long method detector is firing.

More later.

Excerpt from the replay logs:

E0703 14:41:55.416307 16964 player.cpp:84] Long method (1034 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 14:41:55.420699 16964 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.420699 16964 vessel.cpp:111] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.421671 16964 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 14:41:55.421671 16964 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 14:41:55.422669 16964 vessel.cpp:163] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033149185300e+09 s
I0703 14:41:55.423666 16964 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.423666 16964 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.424664 16964 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 14:41:55.546432 16964 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 14:41:55.546432 16964 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 14:41:55.551410 16964 vessel.cpp:111] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.551410 16964 vessel.cpp:163] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033077185297e+09 s
I0703 14:41:55.552384 16964 pile_up.cpp:81] Constructing pile up at 000001838E163850
I0703 14:41:55.553382 16964 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 000001838E163850
I0703 14:41:55.622223 16964 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 14:41:55.622223 16964 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 14:41:55.626186 16964 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:55.627184 16964 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:56.645377 16964 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 14:41:56.646355 16964 pile_up.cpp:106] Destroying pile up at 000001838E163850
E0703 14:41:56.650355 16964 player.cpp:84] Long method (1023 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 14:41:56.653385 16964 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:56.653385 16964 vessel.cpp:111] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:56.654346 16964 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 14:41:56.655354 16964 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 14:41:56.655354 16964 vessel.cpp:163] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033049185300e+09 s
I0703 14:41:56.656340 16964 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:56.657338 16964 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:56.658337 16964 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 14:41:57.015383 16964 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 14:41:57.015383 16964 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 14:41:57.019376 16964 vessel.cpp:111] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:57.020367 16964 vessel.cpp:163] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700032857185316e+09 s
I0703 14:41:57.021380 16964 pile_up.cpp:81] Constructing pile up at 000001838E163850
I0703 14:41:57.021380 16964 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 000001838E163850
I0703 14:41:57.080209 16964 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 14:41:57.080209 16964 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 14:41:57.085194 16964 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:57.085194 16964 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 14:41:58.071563 16964 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 14:41:58.071563 16964 pile_up.cpp:106] Destroying pile up at 000001838E163850
E0703 14:41:58.075546 16964 player.cpp:84] Long method (990 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}

@eggrobin
Copy link
Member

eggrobin commented Jul 3, 2021

Now with more traces (emphasis added). The culprit is the call to Interrupt() in the destruction of the orbit analyser.

OrbitAnalyser::~OrbitAnalyser() {
// Ensure that we do not have a thread still running with references to the
// members of this class when those are destroyed.
Interrupt();
}

This is reminiscent of #2957.

E0703 15:43:29.688395 16940 player.cpp:84] Long method (1031 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 15:43:29.691414 16940 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.692415 16940 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.692415 16940 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 15:43:29.693382 16940 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 15:43:29.694376 16940 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033417185283e+09 s
I0703 15:43:29.694376 16940 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.695376 16940 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.696373 16940 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 15:43:29.703353 16940 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 15:43:29.811066 16940 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 15:43:29.811066 16940 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 15:43:29.816051 16940 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.818048 16940 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033357185292e+09 s
I0703 15:43:29.818048 16940 pile_up.cpp:81] Constructing pile up at 000001DD73D6C830
I0703 15:43:29.819049 16940 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 000001DD73D6C830
I0703 15:43:29.880951 16940 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 15:43:29.881876 16940 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 15:43:29.884868 16940 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.885866 16940 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:29.886862 16940 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 15:43:30.945065 16940 orbit_analyser.cpp:41] ~OrbitAnalyser: Interrupt(); 1058 ms
I0703 15:43:30.946030 16940 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 15:43:30.951018 16940 pile_up.cpp:106] Destroying pile up at 000001DD73D6C830
E0703 15:43:30.952015 16940 player.cpp:84] Long method (1066 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 15:43:30.955006 16940 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:30.955006 16940 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:30.956017 16940 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 15:43:30.957002 16940 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 15:43:30.957002 16940 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033329185295e+09 s
I0703 15:43:30.958000 16940 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:30.958000 16940 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:30.958997 16940 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 15:43:30.959996 16940 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 15:43:31.073719 16940 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 15:43:31.073719 16940 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 15:43:31.077709 16940 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:31.077709 16940 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033269185305e+09 s
I0703 15:43:31.078706 16940 pile_up.cpp:81] Constructing pile up at 000001DD73D6C830
I0703 15:43:31.079576 16940 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 000001DD73D6C830
I0703 15:43:31.131044 16940 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 15:43:31.131044 16940 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 15:43:31.135007 16940 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:31.135998 16940 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 15:43:31.136997 16940 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 15:43:32.117506 16940 orbit_analyser.cpp:41] ~OrbitAnalyser: Interrupt(); 980 ms
I0703 15:43:32.117506 16940 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 15:43:32.122464 16940 pile_up.cpp:106] Destroying pile up at 000001DD73D6C830
E0703 15:43:32.123453 16940 player.cpp:84] Long method (987 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}

@eggrobin
Copy link
Member

eggrobin commented Jul 3, 2021

From breaking the replay under the debugger during this long Interrupt(), I get the stack

for (int n = 0; n <= progress_bar_steps; ++n) {
Instant const t =
parameters.first_time + n / progress_bar_steps * analysis_duration;
if (!ephemeris_->FlowWithFixedStep(t, *instance.value()).ok()) {
template<typename Frame>
absl::Status Ephemeris<Frame>::FlowWithFixedStep(
Instant const& t,
typename Integrator<NewtonianMotionEquation>::Instance& instance) {
if (empty() || t > t_max()) {
Prolong(t);
RETURN_IF_STOPPED;
}
if (instance.time() == DoublePrecision<Instant>(t)) {
return absl::OkStatus();
}
return instance.Solve(t);
template<typename Method, typename Position>
absl::Status
SymmetricLinearMultistepIntegrator<Method, Position>::Instance::Solve(
Instant const& t_final) {
using Acceleration = typename ODE::Acceleration;
using Displacement = typename ODE::Displacement;
using DoubleDisplacement = DoublePrecision<Displacement>;
using DoubleDisplacements = std::vector<DoubleDisplacement>;
using DoublePosition = DoublePrecision<Position>;
auto const& ɑ = integrator_.ɑ_;
auto const& β_numerator = integrator_.β_numerator_;
auto const& β_denominator = integrator_.β_denominator_;
auto& current_state = this->current_state_;
auto& append_state = this->append_state_;
auto const& step = this->step_;
auto const& equation = this->equation_;
if (previous_steps_.size() < order) {
StartupSolve(t_final);
// If |t_final| is not large enough, we may not have generated enough
// points. Bail out, we'll continue the next time |Solve| is called.
if (previous_steps_.size() < order) {
return absl::OkStatus();
}
}
CHECK_EQ(previous_steps_.size(), order);
// Argument checks.
int const dimension = previous_steps_.back().displacements.size();
// Time step.
CHECK_LT(Time(), step);
Time const& h = step;
// Current time.
DoublePrecision<Instant> t = previous_steps_.back().time;
// Order.
int const k = order;
absl::Status status;
std::vector<Position> positions(dimension);
DoubleDisplacements Σj_minus_ɑj_qj(dimension);
std::vector<Acceleration> Σj_βj_numerator_aj(dimension);
while (h <= (t_final - t.value) - t.error) {
// We take advantage of the symmetry to iterate on the list of previous
// steps from both ends.
auto front_it = previous_steps_.begin();
auto back_it = previous_steps_.rbegin();
// This block corresponds to j = 0. We must not pair it with j = k.
{
DoubleDisplacements const& qj = front_it->displacements;
std::vector<Acceleration> const& aj = front_it->accelerations;
double const ɑj = ɑ[0];
double const βj_numerator = β_numerator[0];
for (int d = 0; d < dimension; ++d) {
Σj_minus_ɑj_qj[d] = Scale(-ɑj, qj[d]);
Σj_βj_numerator_aj[d] = βj_numerator * aj[d];
}
++front_it;
}
// The generic value of j, paired with k - j.
for (int j = 1; j < k / 2; ++j) {
DoubleDisplacements const& qj = front_it->displacements;
DoubleDisplacements const& qk_minus_j = back_it->displacements;
std::vector<Acceleration> const& aj = front_it->accelerations;
std::vector<Acceleration> const& ak_minus_j = back_it->accelerations;
double const ɑj = ɑ[j];
double const βj_numerator = β_numerator[j];
for (int d = 0; d < dimension; ++d) {
Σj_minus_ɑj_qj[d] -= Scale(ɑj, qj[d]);
Σj_minus_ɑj_qj[d] -= Scale(ɑj, qk_minus_j[d]);
Σj_βj_numerator_aj[d] += βj_numerator * (aj[d] + ak_minus_j[d]);
}
++front_it;
++back_it;
}
// This block corresponds to j = k / 2. We must not pair it with j = k / 2.
{
DoubleDisplacements const& qj = front_it->displacements;
std::vector<Acceleration> const& aj = front_it->accelerations;
double const ɑj = ɑ[k / 2];
double const βj_numerator = β_numerator[k / 2];
for (int d = 0; d < dimension; ++d) {
Σj_minus_ɑj_qj[d] -= Scale(ɑj, qj[d]);
Σj_βj_numerator_aj[d] += βj_numerator * aj[d];
}
}
// Create a new step in the instance.
t.Increment(h);
previous_steps_.emplace_back();
Step& current_step = previous_steps_.back();
current_step.time = t;
current_step.accelerations.resize(dimension);
current_step.displacements.reserve(dimension);
// Fill the new step. We skip the division by ɑk as it is equal to 1.0.
double const ɑk = ɑ[0];
DCHECK_EQ(ɑk, 1.0);
for (int d = 0; d < dimension; ++d) {
DoubleDisplacement& current_displacement = Σj_minus_ɑj_qj[d];
current_displacement.Increment(h * h *
Σj_βj_numerator_aj[d] / β_denominator);
current_step.displacements.push_back(current_displacement);
DoublePosition const current_position =
DoublePosition() + current_displacement;
positions[d] = current_position.value;
current_state.positions[d] = current_position;
}
status.Update(equation.compute_acceleration(t.value,
positions,
current_step.accelerations));
previous_steps_.pop_front();
ComputeVelocityUsingCohenHubbardOesterwinter();
// Inform the caller of the new state.
RETURN_IF_STOPPED;
current_state.time = t;
append_state(current_state);
template<typename Frame>
void Ephemeris<Frame>::AppendMasslessBodiesStateToTrajectories(
typename NewtonianMotionEquation::SystemState const& state,
std::vector<not_null<DiscreteTrajectory<Frame>*>> const& trajectories) {
Instant const time = state.time.value;
int index = 0;
for (auto& trajectory : trajectories) {
trajectory->Append(
time,
DegreesOfFreedom<Frame>(state.positions[index].value,
state.velocities[index].value));
template<typename Frame>
void DiscreteTrajectory<Frame>::Append(
Instant const& time,
DegreesOfFreedom<Frame> const& degrees_of_freedom) {
CHECK(this->is_root() || time > this->Fork()->time)
<< "Append at " << time << " which is before fork time "
<< this->Fork()->time;
if (!timeline_.empty() && timeline_.cbegin()->first == time) {
LOG(WARNING) << "Append at existing time " << time
<< ", time range = [" << this->front().time << ", "
<< this->back().time << "]";
return;
}
auto it = timeline_.emplace_hint(timeline_.end(),
time,
degrees_of_freedom);
// Decrementing |end()| is much faster than incrementing |it|. Don't ask.
CHECK(--timeline_.end() == it)
<< "Append out of order at " << time << ", last time is "
<< (--timeline_.end())->first;
if (downsampling_.has_value()) {
if (timeline_.size() == 1) {
downsampling_->SetStartOfDenseTimeline(timeline_.begin(), timeline_);
} else {
this->CheckNoForksBefore(this->back().time);
downsampling_->increment_dense_intervals(timeline_);
if (downsampling_->reached_max_dense_intervals()) {
std::vector<TimelineConstIterator> dense_iterators;
// This contains points, hence one more than intervals.
dense_iterators.reserve(downsampling_->max_dense_intervals() + 1);
for (TimelineConstIterator it =
downsampling_->start_of_dense_timeline();
it != timeline_.end();
++it) {
dense_iterators.push_back(it);
}
auto right_endpoints = FitHermiteSpline<Instant, Position<Frame>>(
dense_iterators,
[](auto&& it) -> auto&& { return it->first; },
[](auto&& it) -> auto&& { return it->second.position(); },
[](auto&& it) -> auto&& { return it->second.velocity(); },
downsampling_->tolerance());

Note that the computation of t in orbit_analyser.cpp is obviously broken since 45c84de, because it uses the result of an integer division as a multiplier in [0, 1]; this explains the progress bar instantly changing from 0% to 100%, as reported by @al2me6 on Discord (#3041).

It is however not clear why we end up stuck for an entire second here, since there is a RETURN_IF_STOPPED in the integrator loop just above that append_state

@eggrobin
Copy link
Member

eggrobin commented Jul 3, 2021

More traces. The time is spent in a single call to FitHermiteSpline. The trajectory being a highly excentric and very fast orbit (kerbals jump suborbitally on Earth), it downsamples very poorly, so FitHermiteSpline is very slow.
FitHermiteSpline should probably have a RETURN_IF_STOPPED (it should also be faster, #2961, but that is a different problem).

E0703 18:12:04.888756 11224 player.cpp:84] Long method (878 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 18:12:04.891295 11224 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:04.892396 11224 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:04.892563 11224 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 18:12:04.892745 11224 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 18:12:04.892745 11224 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033149185300e+09 s
I0703 18:12:04.892745 11224 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:04.892745 11224 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:04.892745 11224 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 18:12:04.892745 11224 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 18:12:05.002799 11224 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 18:12:05.002799 11224 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 18:12:05.005759 11224 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.005759 11224 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033077185297e+09 s
I0703 18:12:05.006768 11224 pile_up.cpp:81] Constructing pile up at 0000018930AFCCF0
I0703 18:12:05.006948 11224 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 0000018930AFCCF0
I0703 18:12:05.053092 11224 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 18:12:05.053092 11224 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 18:12:05.056083 11224 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.056083 11224 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.057112 11224 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 18:12:05.921766 20788 discrete_trajectory_body.hpp:228] Append: FitHermiteSpline 879 ms from 10001 dense iterators to 9934 right endpoints
I0703 18:12:05.923226 11224 orbit_analyser.cpp:41] ~OrbitAnalyser: Interrupt(); 866 ms
I0703 18:12:05.925190 11224 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 18:12:05.925442 11224 pile_up.cpp:106] Destroying pile up at 0000018930AFCCF0
E0703 18:12:05.925442 11224 player.cpp:84] Long method (868 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}
I0703 18:12:05.928437 11224 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.929435 11224 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.929435 11224 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 18:12:05.929435 11224 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 18:12:05.929435 11224 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700033049185300e+09 s
I0703 18:12:05.929435 11224 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.929435 11224 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:05.929435 11224 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 18:12:05.929435 11224 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 18:12:06.215755 11224 plugin.cpp:402] Inserted loaded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
E0703 18:12:06.215755 11224 ksp_plugin_adapter.cs:1139] Unpacked part kerbalEVA (Wehrwell Kerman) (E157195E) appeared between BetterLateThanNever and WaitForFixedUpdate.  Linearly extrapolating its position at the previous frame.
I0703 18:12:06.218750 11224 vessel.cpp:115] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:06.218750 11224 vessel.cpp:167] Preparing history of vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8) at -1.51700032857185316e+09 s
I0703 18:12:06.219614 11224 pile_up.cpp:81] Constructing pile up at 0000018930AFCCF0
I0703 18:12:06.219779 11224 part.cpp:219] Adding part kerbalEVA (Wehrwell Kerman) (5E1957E1) to the pile up at 0000018930AFCCF0
I0703 18:12:06.268133 11224 ksp_plugin_adapter.cs:1280] Reporting collision with local scenery runway_collider
I0703 18:12:06.269100 11224 plugin.cpp:543] Collision between kerbalEVA (Wehrwell Kerman) (5E1957E1) and the ground.
I0703 18:12:06.272091 11224 plugin.cpp:623] Removing grounded vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:06.272091 11224 vessel.cpp:77] Destroying vessel Wehrwell Kerman (a62fa545-68ae-4651-b753-47a8600440c8)
I0703 18:12:06.272091 11224 vessel.cpp:81] ~Vessel: StopPrognosticator(); 0 ms
I0703 18:12:07.149072 22496 discrete_trajectory_body.hpp:228] Append: FitHermiteSpline 894 ms from 10001 dense iterators to 9934 right endpoints
I0703 18:12:07.151060 11224 orbit_analyser.cpp:41] ~OrbitAnalyser: Interrupt(); 878 ms
I0703 18:12:07.152773 11224 part.cpp:67] Destroying part kerbalEVA (Wehrwell Kerman) (5E1957E1)
I0703 18:12:07.152927 11224 pile_up.cpp:106] Destroying pile up at 0000018930AFCCF0
E0703 18:12:07.152999 11224 player.cpp:84] Long method (881 ms):
[principia.journal.serialization.FreeVesselsAndPartsAndCollectPileUps.extension] {
  in {
    plugin: 1773956949968
    delta_t: 0.02
  }
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants