Simplified race result handling

This commit is contained in:
Blazico 2026-03-02 14:15:34 +01:00
parent 997f2fb6cd
commit 81c6045f02
3 changed files with 60 additions and 224 deletions

View File

@ -7,7 +7,6 @@ import (
"wwfc/common"
"wwfc/logging"
"wwfc/qr2"
"wwfc/race"
"github.com/logrusorgru/aurora/v3"
)
@ -17,6 +16,7 @@ type RaceResultPlayer struct {
FinishTimeMs int `json:"finish_time_ms"`
CharacterId int `json:"character_id"`
KartId int `json:"kart_id"`
PlayerCount int `json:"player_count"`
}
type RaceResult struct {
@ -104,10 +104,12 @@ func (g *GameSpySession) handleWWFCReport(command common.GameSpyCommand) {
"- PID:", aurora.Cyan(strconv.Itoa(player.Pid)),
"Time:", aurora.Cyan(strconv.Itoa(player.FinishTimeMs)), "ms",
"Char:", aurora.Cyan(strconv.Itoa(player.CharacterId)),
"Kart:", aurora.Cyan(strconv.Itoa(player.KartId)))
"Kart:", aurora.Cyan(strconv.Itoa(player.KartId)),
"Count:", aurora.Cyan(strconv.Itoa(player.PlayerCount)))
// Hand off to qr2 for processing
qr2.ProcessMKWRaceResult(g.User.ProfileId, player.Pid, player.FinishTimeMs, player.CharacterId, player.KartId)
qr2.ProcessMKWRaceResult(g.User.ProfileId, player.Pid, player.FinishTimeMs, player.CharacterId, player.KartId, player.PlayerCount)
case "wl:mkw_race_start_time":
serverTime := time.Now().UnixMilli()
logging.Info(g.ModuleName,
@ -121,15 +123,8 @@ func (g *GameSpySession) handleWWFCReport(command common.GameSpyCommand) {
return
}
// Initialize progress timing data for this race
race.RaceProgressTimings[g.User.ProfileId] = &race.RaceProgressTiming{
ClientStartTime: clientTime,
ServerStartTime: serverTime,
RecentDelays: make([]float64, 0, race.MaxDelays),
}
case "wl:mkw_race_progress_time":
race.HandleRaceProgressTime(g.User.ProfileId, value)
// Store timing data in qr2 module
qr2.StoreRaceStartTime(g.User.ProfileId, clientTime, serverTime)
case "wl:mkw_race_finish_time":
serverTime := time.Now().UnixMilli()
@ -144,9 +139,8 @@ func (g *GameSpySession) handleWWFCReport(command common.GameSpyCommand) {
return
}
// Calculate and log final race delays
race.LogRaceProgressDelay(g.User.ProfileId, clientTime, serverTime)
// Store timing data in qr2 module
qr2.StoreRaceFinishTime(g.User.ProfileId, clientTime, serverTime)
}
}
}

View File

@ -5,14 +5,12 @@ import (
"encoding/binary"
"encoding/gob"
"fmt"
"math"
"os"
"strconv"
"strings"
"time"
"wwfc/common"
"wwfc/logging"
"wwfc/race"
"github.com/logrusorgru/aurora/v3"
)
@ -55,6 +53,17 @@ type RaceResult struct {
var raceResults = map[string]map[int][]RaceResult{} // GroupName -> RaceNumber -> []RaceResult
// Timing storage for delta calculation using start/finish times
var raceStartTimings = map[uint32]struct {
ClientTime int64
ServerTime int64
}{}
var raceFinishTimings = map[uint32]struct {
ClientTime int64
ServerTime int64
}{}
var groups = map[string]*Group{}
func processResvOK(moduleName string, matchVersion int, reservation common.MatchCommandDataReservation, resvOK common.MatchCommandDataResvOK, sender, destination *Session) bool {
@ -334,6 +343,22 @@ func CheckGPReservationAllowed(senderIP uint64, senderPid uint32, destPid uint32
return checkReservationAllowed(moduleName, from, to, joinType)
}
// StoreRaceStartTime stores the start timing data for delta calculation
func StoreRaceStartTime(profileId uint32, clientTime, serverTime int64) {
raceStartTimings[profileId] = struct {
ClientTime int64
ServerTime int64
}{ClientTime: clientTime, ServerTime: serverTime}
}
// StoreRaceFinishTime stores the finish timing data for delta calculation
func StoreRaceFinishTime(profileId uint32, clientTime, serverTime int64) {
raceFinishTimings[profileId] = struct {
ClientTime int64
ServerTime int64
}{ClientTime: clientTime, ServerTime: serverTime}
}
func ProcessNATNEGReport(result byte, ip1 string, ip2 string) {
moduleName := "QR2:NATNEGReport"
@ -549,7 +574,7 @@ func ProcessMKWSelectRecord(profileId uint32, key string, value string) {
}
func ProcessMKWRaceResult(profileId uint32, playerPid int, finishTimeMs int, characterId int, kartId int) {
func ProcessMKWRaceResult(profileId uint32, playerPid int, finishTimeMs int, characterId int, kartId int, playerCount int) {
moduleName := "QR2:MKWRaceResult:" + strconv.FormatUint(uint64(profileId), 10)
mutex.Lock()
@ -578,12 +603,28 @@ func ProcessMKWRaceResult(profileId uint32, playerPid int, finishTimeMs int, cha
return
}
// Get the accumulated lag from race progress timing
// Calculate delta using start/finish times
var delta int
if timing, exists := race.RaceProgressTimings[profileId]; exists && len(timing.RecentDelays) > 0 {
// Get the final smoothed delay and convert to int
finalDelay := timing.RecentDelays[len(timing.RecentDelays)-1]
delta = int(math.Round(finalDelay))
if startTiming, exists := raceStartTimings[profileId]; exists {
if finishTiming, exists := raceFinishTimings[profileId]; exists {
clientElapsedTime := finishTiming.ClientTime - startTiming.ClientTime
serverElapsedTime := finishTiming.ServerTime - startTiming.ServerTime
delta = int(serverElapsedTime - clientElapsedTime)
}
}
// Calculate finish position based on current race results
finishPos := 1
if raceResults[group.GroupName] != nil && len(raceResults[group.GroupName][group.MKWRaceNumber]) > 0 {
// Get current race results for this race number
currentResults := raceResults[group.GroupName][group.MKWRaceNumber]
// Count how many players have finished with better times
for _, existingResult := range currentResults {
if existingResult.FinishTime < uint32(finishTimeMs) {
finishPos++
}
}
}
// Convert race result data to internal format
@ -593,8 +634,8 @@ func ProcessMKWRaceResult(profileId uint32, playerPid int, finishTimeMs int, cha
FinishTime: uint32(finishTimeMs),
CharacterID: uint32(characterId),
VehicleID: uint32(kartId),
PlayerCount: 12, // Default value, could be extracted from race data if available
FinishPos: 0, // Default value, could be calculated from finish times
PlayerCount: uint32(playerCount),
FinishPos: finishPos,
CourseID: group.MKWCourseID,
EngineClassID: group.MKWEngineClassID,
Delta: delta,

View File

@ -1,199 +0,0 @@
package race
import (
"fmt"
"os"
"strconv"
"time"
"wwfc/logging"
"github.com/logrusorgru/aurora/v3"
)
const (
MaxDelays = 20 // Maximum delays to track in rolling window
SmoothingFactor = 0.3 // For exponential smoothing algorithm
)
type DelayMeasurement struct {
Timestamp int64 // Server timestamp when delay was measured
RawDelay float64 // Raw delay measurement
SmoothedDelay float64 // Smoothed delay using exponential smoothing
}
type RaceProgressTiming struct {
ClientStartTime int64 // Client's race start time (absolute timestamp)
ServerStartTime int64 // Server's race start time (absolute timestamp)
RecentDelays []float64 // Rolling window of recent delays
DelayData []DelayMeasurement // All delay measurements for this race
}
// Global map to track race progress timing data by profile ID
var RaceProgressTimings = make(map[uint32]*RaceProgressTiming)
// logFinalRaceDelay logs the final smoothed and unsmoothed delays for a race to a separate file
func logFinalRaceDelay(pid uint32, finalSmoothedDelay float64, finalUnsmoothedDelay float64) {
file, err := os.OpenFile("delay_logs/race_progress_delays.txt", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
if err != nil {
logging.Error("race", "Failed to open race progress delays log file:", err.Error())
return
}
defer file.Close()
// Write to file: PID,Final_Smoothed_Delay,Final_Unsmoothed_Delay
logEntry := fmt.Sprintf("%d,%.2f,%.2f\n", pid, finalSmoothedDelay, finalUnsmoothedDelay)
_, err = file.WriteString(logEntry)
if err != nil {
logging.Error("race", "Failed to write to race progress delays log file:", err.Error())
}
}
// logRaceProgressDelay stores delay measurements in memory for later batch writing
func logRaceProgressDelay(pid uint32, timestamp int64, rawDelay float64, smoothedDelay float64) {
// Get the race start time to use as the race identifier
if timing, exists := RaceProgressTimings[pid]; exists {
// Store delay data in memory for batch writing at race end
// We'll add a field to RaceProgressTiming to store the delay data
if timing.DelayData == nil {
timing.DelayData = make([]DelayMeasurement, 0)
}
measurement := DelayMeasurement{
Timestamp: timestamp,
RawDelay: rawDelay,
SmoothedDelay: smoothedDelay,
}
timing.DelayData = append(timing.DelayData, measurement)
}
}
// addDelayToWindow adds a new delay to the rolling window and returns the smoothed delay
func addDelayToWindow(timing *RaceProgressTiming, newDelay float64) float64 {
// Add new delay to the window
timing.RecentDelays = append(timing.RecentDelays, newDelay)
// Maintain rolling window size
if len(timing.RecentDelays) > MaxDelays {
timing.RecentDelays = timing.RecentDelays[1:]
}
// Calculate smoothed delay using exponential smoothing
var smoothedDelay float64
if len(timing.RecentDelays) == 1 {
// First delay, no smoothing needed
smoothedDelay = newDelay
} else {
// Apply exponential smoothing
previousSmoothed := timing.RecentDelays[len(timing.RecentDelays)-2]
smoothedDelay = SmoothingFactor*newDelay + (1-SmoothingFactor)*previousSmoothed
}
return smoothedDelay
}
// HandleRaceProgressTime handles the wl:mkw_race_progress_time report case
func HandleRaceProgressTime(pid uint32, value string) {
// Parse client absolute timestamp (this is the client's current time)
clientTimestamp, err := strconv.ParseInt(value, 10, 64)
if err != nil {
logging.Error("race", "Failed to parse client progress timestamp:", err.Error())
return
}
serverTime := time.Now().UnixMilli()
// logging.Info("race", "Race progress time:", aurora.Yellow(value), "Server time:", aurora.Yellow(strconv.FormatInt(serverTime, 10)))
// Get or create progress timing for this player
timing, exists := RaceProgressTimings[pid]
if !exists {
logging.Warn("race", "No race start timing found for progress report from profile", aurora.BrightCyan(strconv.FormatUint(uint64(pid), 10)))
return
}
// Calculate client elapsed time: current client timestamp - client start timestamp
clientElapsedTime := clientTimestamp - timing.ClientStartTime
// Calculate server elapsed time: current server time - server start time
serverElapsedTime := serverTime - timing.ServerStartTime
// Calculate delay: client elapsed time - server elapsed time
// This gives us the time difference between what the client thinks has passed vs what the server thinks has passed
delay := float64(clientElapsedTime - serverElapsedTime)
// Add to rolling window and get smoothed delay
smoothedDelay := addDelayToWindow(timing, delay)
// Log this delay measurement to per-race CSV file
logRaceProgressDelay(pid, serverTime, delay, smoothedDelay)
// logging.Info("race",
// "Progress delay:", aurora.Cyan(fmt.Sprintf("%.2f", delay)),
// "Smoothed delay:", aurora.Cyan(fmt.Sprintf("%.2f", smoothedDelay)),
// "Delays tracked:", aurora.Cyan(strconv.Itoa(len(timing.RecentDelays))))
// Progress delays are tracked in memory for smoothing calculation
// Final delays are logged when race finishes
}
// LogRaceProgressDelay logs final race delays and cleans up timing data
func LogRaceProgressDelay(pid uint32, clientFinishTime int64, serverFinishTime int64) {
if timing, exists := RaceProgressTimings[pid]; exists {
// Calculate final unsmoothed delay using start and finish timestamps
finalUnsmoothedDelay := float64((clientFinishTime - timing.ClientStartTime) - (serverFinishTime - timing.ServerStartTime))
// Get final smoothed delay from the rolling window
var finalSmoothedDelay float64
if len(timing.RecentDelays) > 0 {
finalSmoothedDelay = timing.RecentDelays[len(timing.RecentDelays)-1]
}
// Log both delays
logFinalRaceDelay(pid, finalSmoothedDelay, finalUnsmoothedDelay)
// Write all delay measurements to CSV file in batch
writeRaceProgressDelaysToFile(pid, timing)
// Clean up timing data for this player
delete(RaceProgressTimings, pid)
}
}
// writeRaceProgressDelaysToFile writes all stored delay measurements to a CSV file
func writeRaceProgressDelaysToFile(pid uint32, timing *RaceProgressTiming) {
// Create filename with PID and race start time for uniqueness (one file per race per player)
filename := fmt.Sprintf("delay_logs/race_delays_%d_%d.csv", pid, timing.ClientStartTime)
file, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
if err != nil {
logging.Error("race", "Failed to open race delay CSV file:", err.Error())
return
}
defer file.Close()
// Write header if file is empty
fileInfo, _ := file.Stat()
if fileInfo.Size() == 0 {
header := "timestamp,raw_delay,smoothed_delay\n"
_, err = file.WriteString(header)
if err != nil {
logging.Error("race", "Failed to write CSV header:", err.Error())
return
}
}
// Write all delay measurements in batch
for _, measurement := range timing.DelayData {
logEntry := fmt.Sprintf("%d,%.2f,%.2f\n", measurement.Timestamp, measurement.RawDelay, measurement.SmoothedDelay)
_, err = file.WriteString(logEntry)
if err != nil {
logging.Error("race", "Failed to write to race delay CSV file:", err.Error())
return
}
}
}
// CleanupRaceProgressTiming cleans up race progress timing data for a player
func CleanupRaceProgressTiming(pid uint32) {
delete(RaceProgressTimings, pid)
}