diff --git a/code/network/multi_interpolate.cpp b/code/network/multi_interpolate.cpp index fd9cd2949aa..aede2e0e7e3 100644 --- a/code/network/multi_interpolate.cpp +++ b/code/network/multi_interpolate.cpp @@ -4,13 +4,114 @@ SCP_unordered_map Interp_info; extern void multi_ship_record_signal_update(int objnum, TIMESTAMP lower_time_limit, TIMESTAMP upper_time_limit, int prev_packet_index, int current_packet_index); + +// ============================================================================ +// TEMPORARY INSTRUMENTATION - remove before merging. +// +// Answers one question: is interpolation actually running, or is every remote +// ship permanently stuck dead-reckoning in _simulation_mode because the local +// and remote clocks were never synchronized? +// +// Reports once per second to fs2_open.log, aggregated over all interpolated +// objects. Grep the log for "MULTI INTERP". +// ============================================================================ +namespace { + +struct interp_debug_stats { + int warmup_frames = 0; // object-frames spent waiting for a second packet + int interp_frames = 0; // object-frames that actually interpolated between two packets + int sim_frames = 0; // object-frames that dead-reckoned instead + int snap_events = 0; // times the sim-mode "jump to newest packet" fired + int neg_sim_time_events = 0; // times that snap computed a negative sim_time + + // Object-frames for ships the server has deliberately stopped updating -- see the + // Dying/Exploded skip in multi_oo_build_ship_list(). These can only ever dead + // reckon, so counting them in the interp/sim ratio just dilutes it. + int stale_frames = 0; + + // skew = local current_time - newest held packet's remote_missiontime, in ms. + // positive => the local clock has run past every packet we hold (client ahead) + // negative => every packet we hold is stamped in our future (client behind) + // A near-zero average with a small spread is what interpolation needs. + int skew_min = INT_MAX; + int skew_max = INT_MIN; + double skew_sum = 0.0; + int skew_count = 0; + + float snap_sim_time_min = 1e9f; + float snap_sim_time_max = -1e9f; +}; + +interp_debug_stats Interp_debug; +bool Interp_debug_report_scheduled = false; +int Interp_debug_next_report = 0; + +// gated to once per second; safe to call from the per-object path +void interp_debug_report() +{ + const int now = Multi_Timing_Info.get_current_time(); + + // first call in this mission - start the clock rather than dumping a partial second + if (!Interp_debug_report_scheduled) { + Interp_debug_report_scheduled = true; + Interp_debug_next_report = now + 1000; + return; + } + + if (now < Interp_debug_next_report) { + return; + } + Interp_debug_next_report = now + 1000; + + auto& s = Interp_debug; + const int decided = s.interp_frames + s.sim_frames; + + if (decided + s.warmup_frames == 0) { + return; + } + + if (decided > 0) { + mprintf(("MULTI INTERP: %d live obj-frames | interp %d (%.1f%%) | sim %d (%.1f%%) | warmup %d | stale %d | snaps %d (negative sim_time %d)\n", + decided, + s.interp_frames, (100.0f * s.interp_frames) / decided, + s.sim_frames, (100.0f * s.sim_frames) / decided, + s.warmup_frames, s.stale_frames, s.snap_events, s.neg_sim_time_events)); + } else { + mprintf(("MULTI INTERP: no decided obj-frames, %d warmup frames (fewer than 2 packets held)\n", s.warmup_frames)); + } + + if (s.skew_count > 0) { + mprintf(("MULTI INTERP: skew (local - newest packet) avg %.1f ms | min %d | max %d | spread %d ms\n", + s.skew_sum / s.skew_count, s.skew_min, s.skew_max, s.skew_max - s.skew_min)); + } + + if (s.snap_events > 0) { + mprintf(("MULTI INTERP: snap sim_time min %.4f s | max %.4f s\n", s.snap_sim_time_min, s.snap_sim_time_max)); + } + + s = interp_debug_stats(); +} + +} // namespace + +// call this from mission start so the numbers don't carry across missions +void multi_interpolate_debug_reset() +{ + Interp_debug = interp_debug_stats(); + Interp_debug_report_scheduled = false; + Interp_debug_next_report = 0; +} +// ======================= END TEMPORARY INSTRUMENTATION ======================= + /////////////////////////////////////////// // interpolation info management functions // seeks through the packets to find the one that we need, starting from the end, notice we cannot use MULTIPLAYER_CLIENT macro here. We cannot include multi.h void interpolation_manager::reassess_packet_index(vec3d* pos, matrix* ori, physics_info* pip) { - auto current_time = Multi_Timing_Info.get_current_time(); + // Must be the playback clock, not the raw local clock. _packets hold timestamps + // stamped on the source machine's clock, and nothing ever synchronized the two. + auto current_time = Multi_Timing_Info.get_playback_time(_source_player_index); int current_index = static_cast(_packets.size()) - 2; int prev_index = static_cast(_packets.size()) - 1; @@ -58,6 +159,9 @@ void interpolation_manager::interpolate_main(vec3d* pos, matrix* ori, physics_in // To optimize, we should not reassess_packet_index with a negative index. // The index will be made positive by add_packet, once a second packet has been received. if (_upcoming_packet_index < 0 ) { + Interp_debug.warmup_frames++; // TEMP INSTRUMENTATION + interp_debug_report(); // TEMP INSTRUMENTATION + *last_pos = *pos; *last_orient = *ori; @@ -72,23 +176,81 @@ void interpolation_manager::interpolate_main(vec3d* pos, matrix* ori, physics_in reassess_packet_index(pos, ori, pip); + // --- TEMP INSTRUMENTATION: how far has our clock drifted from the newest packet we hold? --- + // Anything past this has not been updated by any rate in the Multi_oo_*_update_times + // tables (slowest is 2500ms), so the server has stopped sending it altogether -- it is + // dying or exploded. Those can only dead reckon, so keep them out of the ratio. + constexpr int INTERP_DEBUG_STALE_MS = 3000; + bool interp_debug_stale = false; + + if (!_packets.empty()) { + const int skew = Multi_Timing_Info.get_current_time() - _packets.front().remote_missiontime; + const int age = Multi_Timing_Info.get_playback_time(_source_player_index) - _packets.front().remote_missiontime; + + interp_debug_stale = (age > INTERP_DEBUG_STALE_MS); + + if (interp_debug_stale) { + Interp_debug.stale_frames++; + } else { + Interp_debug.skew_min = MIN(Interp_debug.skew_min, skew); + Interp_debug.skew_max = MAX(Interp_debug.skew_max, skew); + Interp_debug.skew_sum += skew; + Interp_debug.skew_count++; + } + } + interp_debug_report(); + // --- END TEMP INSTRUMENTATION --- + // if we are off the beaten path if(_simulation_mode) { - + + if (!interp_debug_stale) { Interp_debug.sim_frames++; } // TEMP INSTRUMENTATION + float sim_time = flFrametime; // we need to push this ship up to the limit of where we were on the remote instance, if we haven't already. // then we need to adjust our timing since some of the sim time is used up getting to that last packet. if (!_packets_expended && !_packets.empty()) { - physics_apply_snapshot_manual(*pos, *ori, pip->vel, pip->desired_vel, pip->rotvel, pip->desired_rotvel, _packets.front().snapshot); + // Timestamps descend with index, so the bracket search can only have failed two + // ways: our playback clock ran past the newest packet, or it is behind even the + // oldest one we hold. Dead reckon from whichever end we actually fell off -- + // always taking the newest would teleport the ship a whole buffer forward in the + // second case. Both terms are on the source's clock, hence the playback clock. + const int playback_last = Multi_Timing_Info.get_playback_last_time(_source_player_index); + + const packet_info& reference = (playback_last >= _packets.back().remote_missiontime) + ? _packets.front() : _packets.back(); - sim_time -= (static_cast(_packets.front().remote_missiontime) - static_cast(Multi_Timing_Info.get_last_time())) / TIMESTAMP_FREQUENCY; + physics_apply_snapshot_manual(*pos, *ori, pip->vel, pip->desired_vel, pip->rotvel, pip->desired_rotvel, reference.snapshot); + + sim_time -= (static_cast(reference.remote_missiontime) - static_cast(playback_last)) / TIMESTAMP_FREQUENCY; _packets_expended = true; + + // --- TEMP INSTRUMENTATION: this is the once-per-packet reposition --- + Interp_debug.snap_events++; + Interp_debug.snap_sim_time_min = MIN(Interp_debug.snap_sim_time_min, sim_time); + Interp_debug.snap_sim_time_max = MAX(Interp_debug.snap_sim_time_max, sim_time); + if (sim_time < 0.0f) { + Interp_debug.neg_sim_time_events++; + } + // --- END TEMP INSTRUMENTATION --- } - sim_time = (sim_time > 0.25f) ? 0.25f : sim_time; + // A negative sim_time means our playback clock has not converged on this source + // yet. physics_sim will happily integrate backwards through it, which corrupts + // the ship's state rather than just rewinding it, so clamp both ends. + CLAMP(sim_time, 0.0f, 0.25f); + + // Catching up in one big step is not the same as taking it a frame at a time -- + // physics_sim_rot and the velocity damping are both nonlinear in time, so a + // turning ship lands somewhere slightly wrong. Sub-step it. + constexpr float MAX_SIM_SUBSTEP = 1.0f / 60.0f; - physics_sim(pos, ori, pip, gravity, sim_time); + while (sim_time > 0.0001f) { + const float step = MIN(sim_time, MAX_SIM_SUBSTEP); + physics_sim(pos, ori, pip, gravity, step); + sim_time -= step; + } // we can't trust what the last position was on the local instance, so figure out what it should have been // use flFrametime here because we need to know what the last position would have been if it was accurate in the last frame. @@ -115,8 +277,8 @@ void interpolation_manager::interpolate_main(vec3d* pos, matrix* ori, physics_in return; // we should not try interpolating and siming on the same call, so return. } - // calc what the current timing should be. - float numerator = static_cast(Multi_Timing_Info.get_current_time()) - static_cast(_packets[_prev_packet_index].remote_missiontime); + // calc what the current timing should be. Playback clock, for the same reason as in reassess_packet_index. + float numerator = static_cast(Multi_Timing_Info.get_playback_time(_source_player_index)) - static_cast(_packets[_prev_packet_index].remote_missiontime); float denominator = static_cast(_packets[_upcoming_packet_index].remote_missiontime) - static_cast(_packets[_prev_packet_index].remote_missiontime); // work around for weird situations that might cause NAN (you just never know with multi) @@ -127,6 +289,8 @@ void interpolation_manager::interpolate_main(vec3d* pos, matrix* ori, physics_in // protect against bad floating point arithmetic making orientation or position look off CLAMP(scale, 0.001f, 0.999f); + if (!interp_debug_stale) { Interp_debug.interp_frames++; } // TEMP INSTRUMENTATION + // one by one interpolate the vectors to get the desired results. physics_snapshot temp_state; @@ -165,8 +329,12 @@ void interpolation_manager::interpolate_main(vec3d* pos, matrix* ori, physics_in // correct the ship record for player ships when an up to date packet comes in. void interpolation_manager::reinterpolate_previous(TIMESTAMP stamp, int prev_packet_index, int next_packet_index, vec3d& position, matrix& orientation, vec3d& velocity, vec3d& rotational_velocity) { - // calc what the timing was previously. - float numerator = static_cast(stamp.value()) - static_cast(_packets[prev_packet_index].remote_missiontime); + // calc what the timing was previously. The caller hands us an absolute local timestamp, + // but remote_missiontime is relative to the *source's* mission start, so drop our start + // time and then move the result onto the source's clock before comparing. + int local_time = stamp.value() - Multi_Timing_Info.get_mission_start_time(); + float source_time = static_cast(Multi_Timing_Info.local_time_to_remote(_source_player_index, local_time)); + float numerator = source_time - static_cast(_packets[prev_packet_index].remote_missiontime); float denominator = static_cast(_packets[next_packet_index].remote_missiontime) - static_cast(_packets[prev_packet_index].remote_missiontime); denominator = (denominator > 0.05f) ? denominator : 0.05f; @@ -185,10 +353,17 @@ void interpolation_manager::reinterpolate_previous(TIMESTAMP stamp, int prev_pac // add a packet to the vector, remove the last one if necessary. void interpolation_manager::add_packet(int objnum, int frame, int packet_timestamp, vec3d* position, vec3d* velocity, vec3d* rotational_velocity, vec3d* desired_velocity, vec3d* desired_rotational_velocity, angles* angles, int player_index) { + // Every timestamp in _packets is on this source's clock, and every comparison against + // them goes through it, so keep it current rather than only setting it on the first packet. + _source_player_index = player_index; + + // feed the clock servo, so that get_playback_time() can put our local clock on this + // source's timeline + Multi_Timing_Info.note_packet_time(player_index, packet_timestamp); + if (_packets.empty()) { _packets.push_back(packet_info(frame, packet_timestamp, position, velocity, rotational_velocity, desired_velocity, desired_rotational_velocity, angles)); - _source_player_index = player_index; return; } @@ -230,12 +405,18 @@ void interpolation_manager::add_packet(int objnum, int frame, int packet_timesta if (Objects[objnum].flags[Object::Object_Flags::Player_ship]){ int start_time = Multi_Timing_Info.get_mission_start_time(); - multi_ship_record_signal_update(objnum, TIMESTAMP(start_time + _packets[_prev_packet_index].remote_missiontime), TIMESTAMP(start_time + _packets[_upcoming_packet_index].remote_missiontime), _prev_packet_index, _upcoming_packet_index); + // The ship record is keyed on *local* absolute timestamps, but these are the + // source's clock, so pull them back onto ours before adding our mission start. + auto to_local_stamp = [&](int remote_time) { + return TIMESTAMP(start_time + Multi_Timing_Info.remote_time_to_local(_source_player_index, remote_time)); + }; + + multi_ship_record_signal_update(objnum, to_local_stamp(_packets[_prev_packet_index].remote_missiontime), to_local_stamp(_packets[_upcoming_packet_index].remote_missiontime), _prev_packet_index, _upcoming_packet_index); // if it's not the front packet, we need to update more info past the current packet, as well. // Should be rare though as it is a contingency for out of order packets. if (_upcoming_packet_index > 0) { - multi_ship_record_signal_update(objnum, TIMESTAMP(start_time + _packets[_upcoming_packet_index].remote_missiontime), TIMESTAMP(start_time + _packets[_upcoming_packet_index - 1].remote_missiontime), _upcoming_packet_index, _upcoming_packet_index - 1); + multi_ship_record_signal_update(objnum, to_local_stamp(_packets[_upcoming_packet_index].remote_missiontime), to_local_stamp(_packets[_upcoming_packet_index - 1].remote_missiontime), _upcoming_packet_index, _upcoming_packet_index - 1); } } } @@ -255,15 +436,73 @@ void interpolation_manager::replace_packet(int index, vec3d* pos, matrix* orient } // the hackiest part of the hack? Setting its frame. Let FSO think that it was basically brand new. - // it needs to handle it this way because otherwise another packet might get placed in front of it, + // it needs to handle it this way because otherwise another packet might get placed in front of it, // and we lose our intended effect of interpolating the simulation error away. _packets[index].frame = _packets[index - 1].frame - 1; - _packets[index].remote_missiontime = Multi_Timing_Info.get_last_time(); + // ...and that invented frame number must never reach the server as a rollback reference + _packets[index].synthetic = true; + + // This slot is about to be compared against real packets, which are stamped on the + // source's clock, so it has to be stamped on that clock too -- get_last_time() alone + // is our raw local clock and would drag the whole clock offset into the interpolation + // denominator. + int replacement_time = Multi_Timing_Info.get_playback_last_time(_source_player_index); + + // _packets is ordered newest first, and the bracket search relies on the timestamps + // descending with it. Never let the replacement stamp fall below the next older packet. + if ((index + 1) < static_cast(_packets.size())) { + replacement_time = MAX(replacement_time, _packets[index + 1].remote_missiontime); + } + + _packets[index].remote_missiontime = replacement_time; physics_populate_snapshot_manual(_packets[index].snapshot, *pos, *orient, pip->vel, pip->desired_vel, pip->rotvel, pip->desired_rotvel); } +// Name the moment we last drew this object at, in the terms the server's rollback record +// understands. The naive answer -- newest packet received, plus time since it arrived -- is +// what the fire packets used to send, and it is MULTI_INTERP_BUFFER_MS newer than what was +// actually on screen, so every rolled-back shot was aimed at where the target had not got to yet. +bool interpolation_manager::get_render_reference(int& frame, int& time_after_frame) const +{ + if (_packets.empty()) { + return false; + } + + const int playback = Multi_Timing_Info.get_playback_time(_source_player_index); + + // _packets runs newest first, so the first entry at or before the playback clock is the + // one the rendered position sits just after. Synthetic entries have to be skipped -- + // replace_packet() invents their frame numbers, and the server would rewind to whatever + // unrelated frame that number happens to name. + for (const auto& packet : _packets) { + if (packet.synthetic || (packet.remote_missiontime > playback)) { + continue; + } + + frame = packet.frame; + time_after_frame = playback - packet.remote_missiontime; + + return true; + } + + return false; +} + +bool multi_interpolate_get_render_reference(int objnum, int& frame, int& time_after_frame) +{ + // deliberately find() rather than operator[], so a lookup for an object we never + // tracked does not create an empty entry for it + auto entry = Interp_info.find(objnum); + + if (entry == Interp_info.end()) { + return false; + } + + return entry->second.get_render_reference(frame, time_after_frame); +} + // the contained vectors have been cleared during object shut down. void multi_interpolate_clear_all() { diff --git a/code/network/multi_interpolate.h b/code/network/multi_interpolate.h index 37758de4504..3796d47c973 100644 --- a/code/network/multi_interpolate.h +++ b/code/network/multi_interpolate.h @@ -6,13 +6,21 @@ struct physics_info; -constexpr size_t PACKET_INFO_LIMIT = 4; // we should never need more than 4 packets to do interpolation. Overwrite the oldest ones if we do. +// How much packet history to keep per object. This has to span MULTI_INTERP_BUFFER_MS +// worth of updates or the playback clock falls off the back of the history and the object +// drops to dead reckoning -- worst for the *fastest* updating objects, since they cover +// the least wall time per packet. The tightest rate in the Multi_oo_*_update_times tables +// is 20ms (LAN players and targets), and 11 intervals of that is 220ms, comfortably over +// the 150ms buffer. +constexpr size_t PACKET_INFO_LIMIT = 12; typedef struct packet_info { - int frame; // this allows us to directly compare one packet to another. + int frame; // this allows us to directly compare one packet to another. int remote_missiontime; // the remote timestamp that matches this packet. physics_snapshot snapshot; // the received physics info translated into the physics snapshot type for easy interpolation + bool synthetic; // true if replace_packet() built this, in which case `frame` is a made-up number + // and must never be sent back to the server as a rollback reference packet_info(int frame_in = 0, int time_in = 0, const vec3d* position_in = &vmd_zero_vector, const vec3d* velocity_in = &vmd_zero_vector, const vec3d* rotational_velocity_in = &vmd_zero_vector, const vec3d* desired_velocity_in = &vmd_zero_vector, const vec3d* desired_rotational_velocity_in = &vmd_zero_vector, @@ -20,6 +28,7 @@ typedef struct packet_info { { frame = frame_in; remote_missiontime = time_in; + synthetic = false; snapshot.position = *position_in; snapshot.velocity = *velocity_in; snapshot.rotational_velocity = *rotational_velocity_in; @@ -59,6 +68,13 @@ class interpolation_manager { // adds a new packet, whilst also manually sorting the relevant entries void add_packet(int objnum, int frame, int time_delta, vec3d* position, vec3d* velocity, vec3d* rotational_velocity, vec3d* desired_velocity, vec3d* desired_rotational_velocity, angles* angles, int player_index); void interpolate_main(vec3d* pos, matrix* ori, physics_info* pip, vec3d* last_pos, matrix* last_orient, vec3d* gravity, bool player_ship); + + // Describes the moment this object was last drawn at, as the (server frame, ms after that + // frame) pair that multi_ship_record_find_frame() consumes on the server. Returns false + // if there is no usable history. Fire packets must use this rather than the newest packet + // received: interpolation deliberately draws MULTI_INTERP_BUFFER_MS behind that, and the + // server rewinds every ship to whatever moment the pair resolves to. + bool get_render_reference(int& frame, int& time_after_frame) const; void reinterpolate_previous(TIMESTAMP stamp, int prev_packet_index, int next_packet_index, vec3d& position, matrix& orientation, vec3d& velocity, vec3d& rotational_velocity); int get_hull_comparison_frame() const { return _hull_comparison_frame; } @@ -166,8 +182,15 @@ class interpolation_manager { void multi_interpolate_clear_all(); +// TEMP INSTRUMENTATION - remove along with the debug block in multi_interpolate.cpp +void multi_interpolate_debug_reset(); + void multi_interpolate_clear_helper(int objnum); +// interpolation_manager::get_render_reference for a given object, without exposing Interp_info. +// Returns false if we hold no usable history for it. +bool multi_interpolate_get_render_reference(int objnum, int& frame, int& time_after_frame); + void interpolate_main_helper(int objnum, vec3d* pos, matrix* ori, physics_info* pip, vec3d* last_pos, matrix* last_orient, vec3d* gravity, bool player_ship); extern SCP_unordered_map Interp_info; diff --git a/code/network/multi_obj.cpp b/code/network/multi_obj.cpp index 760b31af85b..f7a5413e8ef 100644 --- a/code/network/multi_obj.cpp +++ b/code/network/multi_obj.cpp @@ -558,6 +558,54 @@ matrix multi_ship_record_lookup_orientation(object* objp, int frame) return Oo_info.frame_info[objp->net_signature].orientations[frame]; } +// Look up the recorded position and orientation, interpolated to the exact moment the client +// saw rather than snapped to a recorded frame. +// +// The record holds one snapshot per server frame -- 33ms apart at the default standalone +// framecap -- and multi_ship_record_find_frame() rounds down to the frame *before* the client's +// moment. Rolling back to that frame alone therefore rewinds every shot up to a full frame too +// early, always in the same direction. Against a target crossing the view that error is +// entirely cross-track, which is where shots stop landing. +void multi_ship_record_lookup_interpolated(object* objp, int frame, int time_after_frame, vec3d* pos, matrix* ori) +{ + Assertion(objp != nullptr, "nullptr given to multi_ship_record_lookup_interpolated. \nThis should be handled earlier in the code, please report!"); + if (objp == nullptr) { + *pos = vmd_zero_vector; + *ori = vmd_identity_matrix; + return; + } + + auto& record = Oo_info.frame_info[objp->net_signature]; + + *pos = record.positions[frame]; + *ori = record.orientations[frame]; + + if (time_after_frame <= 0) { + return; + } + + const int next_frame = (frame + 1 >= MAX_FRAMES_RECORDED) ? 0 : frame + 1; + + if (!Oo_info.timestamps[frame].isFinite() || !Oo_info.timestamps[next_frame].isFinite()) { + return; + } + + // Stepping past cur_frame_index lands on the oldest entry in the ring rather than a later + // frame, which shows up as a non-positive duration. Nothing to interpolate toward, so stay + // on the frame we have. + const int frame_duration = timestamp_get_delta(Oo_info.timestamps[frame], Oo_info.timestamps[next_frame]); + + if (frame_duration <= 0) { + return; + } + + float scale = static_cast(time_after_frame) / static_cast(frame_duration); + CLAMP(scale, 0.0f, 1.0f); + + vm_vec_linear_interpolate(pos, &record.positions[frame], &record.positions[next_frame], scale); + vm_interpolate_matrices(ori, &record.orientations[frame], &record.orientations[next_frame], scale); +} + // quickly lookup how much time has passed between two frames. int multi_ship_record_get_time_elapsed(int original_frame, int new_frame) { @@ -576,7 +624,11 @@ int multi_ship_record_find_time_after_frame(int starting_frame, int ending_frame { starting_frame = starting_frame % MAX_FRAMES_RECORDED; - int return_value = time_elapsed - (timestamp_get_delta(Oo_info.timestamps[ending_frame], Oo_info.timestamps[starting_frame])); + // timestamp_get_delta(before, after) returns after - before, so this has to be + // (starting, ending) to yield the elapsed time between them. Reversed, it returns + // time_elapsed *plus* the gap instead of minus it -- roughly twice the frame interval + // too large. Nothing caught it because the result was computed and then discarded. + int return_value = time_elapsed - (timestamp_get_delta(Oo_info.timestamps[starting_frame], Oo_info.timestamps[ending_frame])); return return_value; } @@ -1223,6 +1275,17 @@ int multi_oo_pack_client_data(ubyte *data, ship* shipp) return packet_size; } +// vm_extract_angles_matrix_alternate returns angles in the range -PI..PI, but the subsystem list packer +// encodes them as an unsigned fraction of a full rotation, so wrap negatives around before sending. +static float multi_oo_normalized_angle(float angle) +{ + if (angle < 0.0f) { + angle += PI2; + } + + return angle / PI2; +} + // pack the appropriate info into the data #define PACK_PERCENT(v) { std::uint8_t upercent; if(v < 0.0f){v = 0.0f;} upercent = (v * 255.0f) <= 255.0f ? (std::uint8_t)(v * 255.0f) : (std::uint8_t)255; memcpy(data + packet_size + header_bytes, &upercent, sizeof(std::uint8_t)); packet_size++; } #define PACK_BYTE(v) { memcpy( data + packet_size + header_bytes, &v, 1 ); packet_size += 1; } @@ -1384,11 +1447,11 @@ int multi_oo_pack_data(net_player *pl, object *objp, ushort oo_flags, ubyte *dat subsystem = GET_NEXT(subsystem)) { flags.push_back(0); // Don't send destroyed subsystems, (another packet handles that), but check to see if the subsystem changed since the last update. - if (MULTIPLAYER_MASTER && (subsystem->current_hits != 0.0f) && (subsystem->current_hits != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_health[i])) { + if (MULTIPLAYER_MASTER && (subsystem->current_hits != 0.0f) && (subsystem->current_hits != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_health[i])) { flags[i] |= OO_SUBSYS_HEALTH; subsys_data.push_back(subsystem->current_hits / subsystem->max_hits); // good thing this cheap because we have to calculate this twice to avoid iterating through the whole system list twice. - Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_health[i] = subsystem->current_hits; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_health[i] = subsystem->current_hits; // this should be safe because we only work with subsystems that have health. // and also track the list of subsystems that we packed by index @@ -1409,34 +1472,34 @@ int multi_oo_pack_data(net_player *pl, object *objp, ushort oo_flags, ubyte *dat } // here we're checking to see if the subsystems rotated enough to send. - if (angs_1 != nullptr && angs_1->b != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_1b[i]) { + if (angs_1 != nullptr && angs_1->b != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_1b[i]) { flags[i] |= OO_SUBSYS_ROTATION_1b; - subsys_data.push_back(angs_1->b / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_1->b)); } - if (angs_1 != nullptr && angs_1->h != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_1h[i]) { + if (angs_1 != nullptr && angs_1->h != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_1h[i]) { flags[i] |= OO_SUBSYS_ROTATION_1h; - subsys_data.push_back(angs_1->h / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_1->h)); } - if (angs_1 != nullptr && angs_1->p != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_1p[i]) { + if (angs_1 != nullptr && angs_1->p != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_1p[i]) { flags[i] |= OO_SUBSYS_ROTATION_1p; - subsys_data.push_back(angs_1->p / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_1->p)); } - if (angs_2 != nullptr && angs_2->b != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_2b[i]) { + if (angs_2 != nullptr && angs_2->b != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_2b[i]) { flags[i] |= OO_SUBSYS_ROTATION_2b; - subsys_data.push_back(angs_2->b / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_2->b)); } - if (angs_2 != nullptr && angs_2->h != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_2h[i]) { + if (angs_2 != nullptr && angs_2->h != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_2h[i]) { flags[i] |= OO_SUBSYS_ROTATION_2h; - subsys_data.push_back(angs_2->h / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_2->h)); } - if (angs_2 != nullptr && angs_2->p != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_2p[i]) { + if (angs_2 != nullptr && angs_2->p != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_2p[i]) { flags[i] |= OO_SUBSYS_ROTATION_2p; - subsys_data.push_back(angs_2->p / PI2); + subsys_data.push_back(multi_oo_normalized_angle(angs_2->p)); } // clang says deleting null pointer has no effect @@ -1448,17 +1511,17 @@ int multi_oo_pack_data(net_player *pl, object *objp, ushort oo_flags, ubyte *dat if (subsystem->system_info->flags[Model::Subsystem_Flags::Translates]) { auto smi = subsystem->submodel_instance_1; - if (smi && smi->canonical_offset.xyz.x != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_x[i]) { + if (smi && smi->canonical_offset.xyz.x != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_x[i]) { flags[i] |= OO_SUBSYS_TRANSLATION_x; subsys_data.push_back(smi->canonical_offset.xyz.x); } - if (smi && smi->canonical_offset.xyz.y != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_y[i]) { + if (smi && smi->canonical_offset.xyz.y != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_y[i]) { flags[i] |= OO_SUBSYS_TRANSLATION_y; subsys_data.push_back(smi->canonical_offset.xyz.y); } - if (smi && smi->canonical_offset.xyz.z != Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].subsystem_z[i]) { + if (smi && smi->canonical_offset.xyz.z != Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].subsystem_z[i]) { flags[i] |= OO_SUBSYS_TRANSLATION_z; subsys_data.push_back(smi->canonical_offset.xyz.z); } @@ -1600,8 +1663,8 @@ int multi_oo_unpack_client_data(net_player* pl, ubyte* data, bool keep_data) int offset = 0; - // read flag info - ushort in_flags; + // read flag info -- this is packed as a single byte, so it must be read back as one + ubyte in_flags; memcpy(&in_flags, data, sizeof(ubyte)); offset++; @@ -1895,7 +1958,7 @@ int multi_oo_unpack_data(net_player* pl, ubyte* data, int seq_num, int time_delt full_physics = true; } - int r5 = multi_pack_unpack_desired_vel_and_desired_rotvel(0, full_physics, data + offset, &pobjp->phys_info, &local_desired_vel); + int r5 = multi_pack_unpack_desired_vel_and_desired_rotvel(0, full_physics, data + offset, &new_phys_info, &local_desired_vel); offset += r5; // change it back to global coordinates. vm_vec_unrotate(&new_phys_info.desired_vel, &local_desired_vel, &new_orient); @@ -1904,7 +1967,13 @@ int multi_oo_unpack_data(net_player* pl, ubyte* data, int seq_num, int time_delt new_phys_info.desired_rotvel = new_phys_info.rotvel; } - Interp_info[objnum].add_packet(objnum, seq_num, time_delta, &new_pos, &new_phys_info.vel, &new_phys_info.rotvel, &new_phys_info.desired_vel, &new_phys_info.desired_rotvel, &new_angles, pl->player_id); + // NOTE: this wants an *index* into Net_players, not the network-level player_id. + // pl always points into Net_players, on both the client (where it is the server) + // and the server (where it is the sending client). Anything out of range is + // treated as "unknown source" downstream. + const int source_index = (pl != nullptr) ? NET_PLAYER_INDEX(pl) : -1; + + Interp_info[objnum].add_packet(objnum, seq_num, time_delta, &new_pos, &new_phys_info.vel, &new_phys_info.rotvel, &new_phys_info.desired_vel, &new_phys_info.desired_rotvel, &new_angles, source_index); } // Packet processing needs to stop here if the ship is still arriving, leaving, dead or dying to prevent bugs. @@ -2304,7 +2373,7 @@ void multi_oo_reset_timestamp(net_player *pl, object *objp, int range, int in_co // reset the timestamp for this object if(objp->type == OBJ_SHIP){ - Oo_info.player_frame_info[pl->player_id].last_sent[objp->net_signature].timestamp = _timestamp(stamp); + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[objp->net_signature].timestamp = _timestamp(stamp); } } @@ -2331,7 +2400,7 @@ int multi_oo_maybe_update(net_player *pl, object *obj, ubyte *data) // determine what the timestamp is for this object if(obj->type == OBJ_SHIP){ - stamp = Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].timestamp; + stamp = Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].timestamp; } else { return 0; } @@ -2377,10 +2446,10 @@ int multi_oo_maybe_update(net_player *pl, object *obj, ubyte *data) multi_oo_reset_timestamp(pl, obj, range, in_cone); // position should be almost constant, except for ships that aren't moving. - if ( (Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].position != obj->pos) && (vm_vec_mag_quick(&obj->phys_info.vel) > 0.0f ) ) { + if ( (Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].position != obj->pos) && (vm_vec_mag_quick(&obj->phys_info.vel) > 0.0f ) ) { oo_flags |= OO_POS_AND_ORIENT_NEW; // update the last position sent, will be done in each of the cases below. - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].position = obj->pos; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].position = obj->pos; } // same with orientation else if (obj->phys_info.rotvel != vmd_zero_vector) { oo_flags |= OO_POS_AND_ORIENT_NEW; @@ -2414,9 +2483,9 @@ int multi_oo_maybe_update(net_player *pl, object *obj, ubyte *data) } // maybe update hull - if(Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].hull != obj->hull_strength){ + if(Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].hull != obj->hull_strength){ oo_flags |= (OO_HULL_NEW); - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].hull = obj->hull_strength; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].hull = obj->hull_strength; } float temp_max = shield_get_max_quad(obj); @@ -2434,15 +2503,15 @@ int multi_oo_maybe_update(net_player *pl, object *obj, ubyte *data) if (all_max) { // shields are currently perfect, were they perfect last time? - if ( !Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].perfect_shields_sent){ + if ( !Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].perfect_shields_sent){ // send the newly perfected shields oo_flags |= OO_SHIELDS_NEW; } // make sure to mark it as perfect for next time. - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].perfect_shields_sent = true; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].perfect_shields_sent = true; } // if they're not perfect, make sure they're marked as not perfect. else { - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].perfect_shields_sent = false; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].perfect_shields_sent = false; oo_flags |= OO_SHIELDS_NEW; } @@ -2450,17 +2519,17 @@ int multi_oo_maybe_update(net_player *pl, object *obj, ubyte *data) ai_info *aip = &Ai_info[shipp->ai_index]; // check to see if the AI mode updated - if ((Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].ai_mode != aip->mode) - || (Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].ai_submode != aip->submode) - || (Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].target_signature != aip->target_signature)) { + if ((Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].ai_mode != aip->mode) + || (Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].ai_submode != aip->submode) + || (Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].target_signature != aip->target_signature)) { // send, if so. oo_flags |= OO_AI_NEW; // set new values to check against later. - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].ai_mode = aip->mode; - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].ai_submode = aip->submode; - Oo_info.player_frame_info[pl->player_id].last_sent[net_sig_idx].target_signature = aip->target_signature; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].ai_mode = aip->mode; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].ai_submode = aip->submode; + Oo_info.player_frame_info[NET_PLAYER_INDEX(pl)].last_sent[net_sig_idx].target_signature = aip->target_signature; } // finally, pack stuff only if we have to @@ -2736,6 +2805,8 @@ void multi_init_oo_and_ship_tracker() // Finally init the new timing system. Multi_Timing_Info.set_mission_start_time(); + multi_interpolate_debug_reset(); // TEMP INSTRUMENTATION + // reset datarate stamp now extern int OO_gran; for(int i=0; i(mission_time * MILLISECONDS_PER_SECOND); _in_game_time_set = true; + + // _current_time is about to move by a large step that has nothing to do with + // elapsed time, so every offset measured against the old one is meaningless. + reset_source_clocks(); + } +} + +///////////////////////////////// +// Per-source playback clocks + +void multiplayer_timing_info::reset_source_clocks() +{ + for (auto& sc : _source_clocks) { + sc.acquired = false; + sc.windows_closed = 0; + sc.offset = 0; + sc.target_offset = 0; + sc.window_min_skew = INT_MAX; + sc.window_has_sample = false; + sc.window_end = 0; + } +} + +// Called for every position packet that arrives, from add_packet(). +void multiplayer_timing_info::note_packet_time(int player_index, int remote_time) +{ + if (!valid_source(player_index)) { + return; + } + + auto& sc = _source_clocks[player_index]; + + // How far our clock reads ahead of the timestamp this packet was stamped with. + // This is (clock offset + that packet's network delay), and the delay is always + // positive, so the *minimum* skew over a window is the cleanest estimate of the + // offset alone -- it is the packet that got here fastest. + const int skew = _current_time - remote_time; + + if (!sc.acquired) { + // Nothing is drawing off this clock yet, so take the estimate immediately + // instead of slewing in from a meaningless zero. It is only a rough estimate + // though -- one packet, measured while the mission is still starting up -- so + // the short windows that follow keep snapping until it settles. + sc.acquired = true; + sc.windows_closed = 0; + sc.offset = -skew - MULTI_INTERP_BUFFER_MS; + sc.target_offset = sc.offset; + sc.window_min_skew = skew; + sc.window_has_sample = true; + sc.window_end = _current_time + MULTI_CLOCK_ACQUIRE_WINDOW_MS; + return; + } + + if (!sc.window_has_sample || (skew < sc.window_min_skew)) { + sc.window_min_skew = skew; + sc.window_has_sample = true; + } +} + +// Once per frame, from update_current_time(). +void multiplayer_timing_info::update_source_clocks() +{ + const int frame_delta = _current_time - _last_time; + + for (auto& sc : _source_clocks) { + if (!sc.acquired) { + continue; + } + + // window closed, so re-aim at whatever the best packet in it told us + if (_current_time >= sc.window_end) { + if (sc.window_has_sample) { + sc.target_offset = -sc.window_min_skew - MULTI_INTERP_BUFFER_MS; + } + + // While still acquiring, take each estimate outright rather than slewing onto + // it. Slewing costs seconds of dead reckoning, and the early samples are poor + // enough that one snap onto the first of them lands well short. + const bool still_acquiring = (sc.windows_closed < MULTI_CLOCK_ACQUIRE_WINDOWS); + + if (still_acquiring) { + sc.offset = sc.target_offset; + } + + sc.windows_closed++; + + sc.window_has_sample = false; + sc.window_min_skew = INT_MAX; + sc.window_end = _current_time + (still_acquiring ? MULTI_CLOCK_ACQUIRE_WINDOW_MS : MULTI_CLOCK_WINDOW_MS); + } + + const int diff = sc.target_offset - sc.offset; + + if (diff == 0) { + continue; + } + + // A correction this large is a real discontinuity in the source's clock, not + // drift. Slewing across it would take many seconds of visibly wrong motion. + if ((diff >= MULTI_CLOCK_SNAP_THRESHOLD_MS) || (diff <= -MULTI_CLOCK_SNAP_THRESHOLD_MS)) { + sc.offset = sc.target_offset; + continue; + } + + if (frame_delta <= 0) { + continue; + } + + // Cap the correction at a quarter of the frame. Playback time is + // (_current_time + offset), so an offset moving faster than the frame itself + // would run playback backwards and drag every interpolated ship back with it. + // At a quarter, playback always advances, between 0.75x and 1.25x real time. + const int max_step = MAX(1, frame_delta / 4); + + if (diff > max_step) { + sc.offset += max_step; + } else if (diff < -max_step) { + sc.offset -= max_step; + } else { + sc.offset = sc.target_offset; + } + } +} + +int multiplayer_timing_info::get_playback_time(int player_index) const +{ + if (!valid_source(player_index) || !_source_clocks[player_index].acquired) { + return _current_time; } + + return _current_time + _source_clocks[player_index].offset; +} + +int multiplayer_timing_info::get_playback_last_time(int player_index) const +{ + if (!valid_source(player_index) || !_source_clocks[player_index].acquired) { + return _last_time; + } + + return _last_time + _source_clocks[player_index].offset; +} + +int multiplayer_timing_info::remote_time_to_local(int player_index, int remote_time) const +{ + if (!valid_source(player_index) || !_source_clocks[player_index].acquired) { + return remote_time; + } + + // playback == _current_time + offset, so the local time matching remote_time + // is remote_time - offset. + return remote_time - _source_clocks[player_index].offset; +} + +int multiplayer_timing_info::local_time_to_remote(int player_index, int local_time) const +{ + if (!valid_source(player_index) || !_source_clocks[player_index].acquired) { + return local_time; + } + + return local_time + _source_clocks[player_index].offset; } diff --git a/code/network/multi_time_manager.h b/code/network/multi_time_manager.h index 84f08e614f2..1dcb2b1331c 100644 --- a/code/network/multi_time_manager.h +++ b/code/network/multi_time_manager.h @@ -8,6 +8,39 @@ #include +// How far behind a source's newest packet the playback clock should sit, in milliseconds. +// This is the main tuning knob for interpolation. It buys smoothness at the cost of +// showing remote ships slightly in the past, so: +// - it must exceed a source's per-object update interval, or playback runs past the +// newest packet before the next one lands and the object falls back to dead reckoning +// - it must stay under (PACKET_INFO_LIMIT - 1) * that interval, or playback falls off +// the back of the packet history and the object dead reckons for the opposite reason +// See the Multi_oo_*_update_times tables in multi_obj.cpp for the intervals in play. +// Sized against Multi_oo_target_update_times (66/50/30/20ms by update level) rather than +// the slower tables: your target updates fastest, and it is the one ship where showing the +// past costs you shots. Anything slower than this -- distant or rear-arc ships -- falls +// back to dead reckoning, which is the right answer for a ship you hear from twice a second +// anyway. Every millisecond here is a millisecond of lead you have to guess with no visual +// cue, because the fire packet's reference does not account for it (see send_primary_fired_packet). +constexpr int MULTI_INTERP_BUFFER_MS = 150; + +// How long a window of packets to gather before re-aiming the servo, in milliseconds. +constexpr int MULTI_CLOCK_WINDOW_MS = 1000; + +// Early windows are short and end in a snap rather than a slew. Skew readings taken while +// both machines are still settling out of mission load are not representative -- measured +// ~50ms against a steady state of ~195ms -- so a single early estimate is worth little, and +// correcting it at slew rate costs seconds of dead reckoning at the start of every mission. +// Snapping repeatedly over the first couple of seconds rides the estimate down instead. +constexpr int MULTI_CLOCK_ACQUIRE_WINDOW_MS = 250; +constexpr int MULTI_CLOCK_ACQUIRE_WINDOWS = 8; + +// A correction larger than this means the source's clock genuinely jumped (mission +// restart, in-game join, a huge stall) rather than drifted. Snap instead of slewing; +// slewing across a gap this size would take painfully long and look worse. +constexpr int MULTI_CLOCK_SNAP_THRESHOLD_MS = 1000; + + class multiplayer_timing_info { private: TIMESTAMP _start_time; // when did the multiplayer mission start @@ -15,23 +48,53 @@ class multiplayer_timing_info { int _last_time; // time delta, how much time passed, last frame? Useful when switching back from simulation mode to interpolation int _skipped_time; // time delta, how much has time this instance has "skipped" because it is falling behind the server // getting behind the server like that *should* be exceedingly rare, should always be 0 on server - - int _proposed_skip_time; // until skip time is finalized, we need to + + int _proposed_skip_time; // until skip time is finalized, we need to bool _in_game_time_set; - std::array _most_recent_frame; + std::array _most_recent_frame; + + // Every machine starts its mission clock independently, at the end of its own + // game_level_init(), and nothing ever reconciles them. On top of that offset sits + // the network delay of each individual packet. So a timestamp that arrived from + // another machine cannot be compared against _current_time directly. + // + // This tracks, per source, the offset that converts our local clock into one that + // *is* comparable with that source's packet timestamps, deliberately biased to sit + // MULTI_INTERP_BUFFER_MS behind that source's newest packet. Interpolation reads + // the result through get_playback_time(). + // + // It has to be per-source: a client only ever hears from the server, but the server + // hears from every client, and no two of those clocks agree. + struct source_clock { + bool acquired; // have we heard from this source at all? + int windows_closed; // short snapping windows give way to long slewing ones + int offset; // applied, slewed offset. playback = _current_time + offset + int target_offset; // where the servo is heading + + int window_min_skew; // smallest (local - remote) seen in the window so far + bool window_has_sample; + int window_end; // local time at which we re-aim + }; + + std::array _source_clocks; // for in-game joiners, adjust local timing and then reset proposed time. void finalize_skip_time() { _skipped_time += _proposed_skip_time; _proposed_skip_time = 0; } + void reset_source_clocks(); + void update_source_clocks(); + + static bool valid_source(int player_index) { return (player_index >= 0) && (player_index < MAX_PLAYERS); } + public: multiplayer_timing_info(); // aka reset the class. Needs to be called every time the mission starts. void set_mission_start_time(); - // this was not part of the original design, but is useful when matching up + // this was not part of the original design, but is useful when matching up // timestamps to what is kept internally in this class. int get_mission_start_time() { return _start_time.value(); } @@ -41,6 +104,30 @@ class multiplayer_timing_info { int get_last_time() { return _last_time; } + // Record that a packet stamped remote_time arrived from player_index. Feeds the servo. + void note_packet_time(int player_index, int remote_time); + + // Local time expressed on player_index's clock, biased to sit MULTI_INTERP_BUFFER_MS + // behind that source's newest packet. This -- not get_current_time() -- is what any + // comparison against a received timestamp should use. + int get_playback_time(int player_index) const; + + // Same, for the previous frame. + int get_playback_last_time(int player_index) const; + + // Convert a timestamp received from player_index into the local _current_time that + // corresponds to it. Inverse of get_playback_time(). + int remote_time_to_local(int player_index, int remote_time) const; + + // Convert a local _current_time-relative value into player_index's clock, so it can + // be compared against timestamps received from that source. + int local_time_to_remote(int player_index, int local_time) const; + + bool source_clock_acquired(int player_index) const + { + return valid_source(player_index) && _source_clocks[player_index].acquired; + } + // push local time forward or back on clients based on received server times // this will likely only ever be used for in-game joining, which is not ready. //void set_proposed_skip_time(int candidate) { _proposed_skip_time = candidate; } diff --git a/code/network/multimsgs.cpp b/code/network/multimsgs.cpp index e7b5d9a677d..a1f5e8439b6 100644 --- a/code/network/multimsgs.cpp +++ b/code/network/multimsgs.cpp @@ -2646,7 +2646,7 @@ void process_ship_kill_packet( ubyte *data, header *hinfo ) } // maybe set wash_killed - if (extra_death_info & EXTRA_DEATH_VAPORIZED) { + if (extra_death_info & EXTRA_DEATH_WASHED) { Ships[sobjp->instance].wash_killed = 1; } @@ -7633,7 +7633,8 @@ void process_homing_weapon_info( ubyte *data, header *hinfo ) } if (flags & HWIF_BIG_UPDATE) { - wp->creation_time = Missiontime + missile_lifetime; + // the sender packed the missile's age, so walk creation_time back from now to recover it + wp->creation_time = Missiontime - missile_lifetime; weapon_objp->pos = missile_pos; weapon_objp->orient = orient_in; wp->launch_speed = launch_speed; @@ -7846,9 +7847,22 @@ void send_non_homing_fired_packet(ship* shipp, int banks_or_number_of_missiles_f ADD_DATA(flags); ADD_USHORT(ref_objp->net_signature); - // We need the time elpased, so send the last frame we got from the server and how much time has happened since then. - int last_received_frame = multi_client_lookup_frame_idx(); - auto time_elapsed = static_cast(Multi_Timing_Info.get_current_time() - multi_client_lookup_frame_timestamp()); + // The server rewinds every ship to whatever moment this pair resolves to, so it has to name + // the moment we actually *drew* ref_objp at. Interpolation places that MULTI_INTERP_BUFFER_MS + // behind the newest packet we hold, so asking for "newest frame received, plus time since it + // arrived" aims the rollback at where the target had not got to yet -- which misses, worst on + // fast crossing targets where the error is mostly cross-track. + int last_received_frame, elapsed; + + if (!multi_interpolate_get_render_reference(OBJ_INDEX(ref_objp), last_received_frame, elapsed)) { + // no usable interpolation history for the reference object, so fall back to the old + // approximation rather than dropping the shot + last_received_frame = multi_client_lookup_frame_idx(); + elapsed = Multi_Timing_Info.get_current_time() - multi_client_lookup_frame_timestamp(); + } + + CLAMP(elapsed, 0, 65535); + auto time_elapsed = static_cast(elapsed); ADD_INT(last_received_frame); ADD_USHORT(time_elapsed); @@ -7885,6 +7899,67 @@ void send_non_homing_fired_packet(ship* shipp, int banks_or_number_of_missiles_f multi_io_send(Net_player, data, packet_size); } +// ============================================================================ +// TEMPORARY INSTRUMENTATION - remove before merging. +// +// Answers: is rollback actually running on this server, and what moment is it +// rewinding to? Reports once per second to the *server's* fs2_open.log. +// Grep for "MULTI ROLLBACK". +// ============================================================================ +namespace { + +struct rollback_debug_stats { + int packets = 0; // non-homing fire packets received + int no_rollback_path = 0; // option off, or the reference object was missing / not a ship + int frame_too_old = 0; // find_frame rejected it -- outside the MAX_FRAMES_RECORDED window + int rolled_back = 0; // actually queued a rollback shot + + int elapsed_min = INT_MAX; // ms past the reference frame that the client asked for + int elapsed_max = INT_MIN; + + // time_after_frame: how far past the resolved frame the client's moment actually fell. + // The rewind snaps to whole recorded frames, so this much is thrown away on every shot. + int residual_min = INT_MAX; + int residual_max = INT_MIN; +}; + +rollback_debug_stats Rollback_debug; +int Rollback_debug_next_report = 0; + +void rollback_debug_report() +{ + const int now = timestamp(); + + if (Rollback_debug_next_report == 0) { + Rollback_debug_next_report = now + 1000; + return; + } + + if (now < Rollback_debug_next_report) { + return; + } + Rollback_debug_next_report = now + 1000; + + auto& s = Rollback_debug; + + if (s.packets == 0) { + return; + } + + mprintf(("MULTI ROLLBACK: %d fire packets | rolled back %d | no-rollback path %d | frame too old %d\n", + s.packets, s.rolled_back, s.no_rollback_path, s.frame_too_old)); + + if (s.rolled_back > 0) { + mprintf(("MULTI ROLLBACK: client elapsed %d-%d ms | discarded sub-frame residual %d-%d ms\n", + s.elapsed_min, s.elapsed_max, s.residual_min, s.residual_max)); + } + + s = rollback_debug_stats(); +} + +} // namespace +// ======================= END TEMPORARY INSTRUMENTATION ======================= + void process_non_homing_fired_packet(ubyte* data, header* hinfo) { int offset; // linked; @@ -7942,7 +8017,12 @@ void process_non_homing_fired_packet(ubyte* data, header* hinfo) object* objp_ref = multi_get_network_object(target_ref); + Rollback_debug.packets++; // TEMP INSTRUMENTATION + rollback_debug_report(); // TEMP INSTRUMENTATION + if ((Is_standalone && !Multi_options_g.std_rollback) || !objp_ref || (objp_ref->type != OBJ_SHIP)) { + Rollback_debug.no_rollback_path++; // TEMP INSTRUMENTATION + // new way failed, use the old new way. if (objp_ref != nullptr){ @@ -7968,8 +8048,18 @@ void process_non_homing_fired_packet(ubyte* data, header* hinfo) int time_after_frame = multi_ship_record_find_time_after_frame(client_frame, frame, static_cast(time_elapsed)); Assertion(time_after_frame >= 0, "Primary fire packet processor found an invalid time_after_frame of %d", time_after_frame); - vec3d new_tar_pos = multi_ship_record_lookup_position(objp_ref, frame); - matrix new_tar_ori = multi_ship_record_lookup_orientation(objp_ref, frame); + // --- TEMP INSTRUMENTATION --- + Rollback_debug.rolled_back++; + Rollback_debug.elapsed_min = MIN(Rollback_debug.elapsed_min, static_cast(time_elapsed)); + Rollback_debug.elapsed_max = MAX(Rollback_debug.elapsed_max, static_cast(time_elapsed)); + Rollback_debug.residual_min = MIN(Rollback_debug.residual_min, time_after_frame); + Rollback_debug.residual_max = MAX(Rollback_debug.residual_max, time_after_frame); + // --- END TEMP INSTRUMENTATION --- + + // interpolate to the moment the client actually saw, not just the frame before it + vec3d new_tar_pos; + matrix new_tar_ori; + multi_ship_record_lookup_interpolated(objp_ref, frame, time_after_frame, &new_tar_pos, &new_tar_ori); // find out where the angle to the new primary fire should be, by // rotating the vector @@ -8003,6 +8093,7 @@ void process_non_homing_fired_packet(ubyte* data, header* hinfo) } // if the new way fails for some reason, use the old way. else { + Rollback_debug.frame_too_old++; // TEMP INSTRUMENTATION nprintf(("Network", "Rollback was not performed because the frame sent by the client is either too old or invalid.. Using the old system.\n")); if (secondary) { // if this is a rollback shot from a dumbfire secondary, we have to mark this as a diff --git a/code/network/multiutil.cpp b/code/network/multiutil.cpp index d9deec24046..47f6a014913 100644 --- a/code/network/multiutil.cpp +++ b/code/network/multiutil.cpp @@ -3625,9 +3625,9 @@ int multi_pack_unpack_desired_vel_and_desired_rotvel( int write, bool full_physi a = bitbuffer_get_signed(&buf,5); b = bitbuffer_get_signed(&buf,5); c = bitbuffer_get_signed(&buf,5); - pi->rotvel.xyz.x = pi->max_rotvel.xyz.x * i2fl(a)/15.0f; - pi->rotvel.xyz.y = pi->max_rotvel.xyz.y * i2fl(b)/15.0f; - pi->rotvel.xyz.z = pi->max_rotvel.xyz.z * i2fl(c)/15.0f; + pi->desired_rotvel.xyz.x = pi->max_rotvel.xyz.x * i2fl(a)/15.0f; + pi->desired_rotvel.xyz.y = pi->max_rotvel.xyz.y * i2fl(b)/15.0f; + pi->desired_rotvel.xyz.z = pi->max_rotvel.xyz.z * i2fl(c)/15.0f; }