Race results API integration

api/mkw_rr.go

@@ -0,0 +1,58 @@
+package api
+
+import (
+	"encoding/json"
+	"net/http"
+	"net/url"
+	"strconv"
+	"wwfc/qr2"
+)
+
+type RaceResultInfo struct {
+	Results map[int][]qr2.RaceResult `json:"results"`
+}
+
+func HandleMKWRR(w http.ResponseWriter, r *http.Request) {
+	u, err := url.Parse(r.URL.String())
+	if err != nil {
+		w.WriteHeader(http.StatusBadRequest)
+		return
+	}
+
+	query, err := url.ParseQuery(u.RawQuery)
+	if err != nil {
+		w.WriteHeader(http.StatusBadRequest)
+		return
+	}
+
+	groupNames := query["id"]
+	if len(groupNames) != 1 {
+		w.WriteHeader(http.StatusBadRequest)
+		return
+	}
+
+	results := qr2.GetRaceResultsForGroup(query["id"][0])
+	if results == nil {
+		w.WriteHeader(http.StatusNotFound)
+		return
+	}
+
+	var jsonData []byte
+	if len(results) == 0 {
+		w.WriteHeader(http.StatusNotFound)
+		return
+	} else {
+		jsonData, err = json.Marshal(RaceResultInfo{
+			Results: results,
+		})
+		if err != nil {
+			w.WriteHeader(http.StatusInternalServerError)
+			return
+		}
+	}
+
+	w.Header().Set("Content-Type", "application/json")
+	w.Header().Set("Access-Control-Allow-Origin", "*")
+	w.Header().Set("Content-Length", strconv.Itoa(len(jsonData)))
+	w.Write(jsonData)
+}

gpcm/report.go

@@ -3,9 +3,11 @@ package gpcm
 import (
 	"encoding/json"
 	"strconv"
+	"time"
 	"wwfc/common"
 	"wwfc/logging"
 	"wwfc/qr2"
+	"wwfc/race"
 
 	"github.com/logrusorgru/aurora/v3"
 )
@@ -96,13 +98,55 @@ func (g *GameSpySession) handleWWFCReport(command common.GameSpyCommand) {
 			logging.Info(g.ModuleName, "Race result version:", aurora.Yellow(raceResult.ClientReportVersion))
 
 			player := raceResult.Player
+
 			logging.Info(g.ModuleName,
 				"Player",
 				"- 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)))
-			//TODO : Hand off to qr2 for processing instead of logging each field here
+
+			// Hand off to qr2 for processing
+			qr2.ProcessMKWRaceResult(g.User.ProfileId, player.Pid, player.FinishTimeMs, player.CharacterId, player.KartId)
+		case "wl:mkw_race_start_time":
+			serverTime := time.Now().UnixMilli()
+			logging.Info(g.ModuleName,
+				"Race start time:", aurora.Yellow(value),
+				"Server time:", aurora.Yellow(strconv.FormatInt(serverTime, 10)))
+
+			// Parse client timestamp
+			clientTime, err := strconv.ParseInt(value, 10, 64)
+			if err != nil {
+				logging.Error(g.ModuleName, "Failed to parse client timestamp:", err.Error())
+				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)
+
+		case "wl:mkw_race_finish_time":
+			serverTime := time.Now().UnixMilli()
+			logging.Info(g.ModuleName,
+				"Race finish time:", aurora.Yellow(value),
+				"Server time:", aurora.Yellow(strconv.FormatInt(serverTime, 10)))
+
+			// Parse client timestamp
+			clientTime, err := strconv.ParseInt(value, 10, 64)
+			if err != nil {
+				logging.Error(g.ModuleName, "Failed to parse client finish timestamp:", err.Error())
+				return
+			}
+
+			// Calculate and log final race delays
+			race.LogRaceProgressDelay(g.User.ProfileId, clientTime, serverTime)
 		}
+
 	}
 }

nas/main.go

@@ -177,6 +177,12 @@ func handleRequest(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
+	// Check for /api/mkw_rr
+	if r.URL.Path == "/api/mkw_rr" {
+		api.HandleMKWRR(w, r)
+		return
+	}
+
 	logging.Info("NAS", aurora.Yellow(r.Method), aurora.Cyan(r.URL), "via", aurora.Cyan(r.Host), "from", aurora.BrightCyan(r.RemoteAddr))
 	replyHTTPError(w, 404, "404 Not Found")
 }

qr2/group.go

@@ -5,12 +5,14 @@ import (
 	"encoding/binary"
 	"encoding/gob"
 	"fmt"
+	"math"
 	"os"
 	"strconv"
 	"strings"
 	"time"
 	"wwfc/common"
 	"wwfc/logging"
+	"wwfc/race"
 
 	"github.com/logrusorgru/aurora/v3"
 )
@@ -31,6 +33,28 @@ type Group struct {
 	MKWEngineClassID int
 }
 
+type RaceResultPlayer struct {
+	Pid          int `json:"pid"`
+	FinishTimeMs int `json:"finish_time_ms"`
+	CharacterId  int `json:"character_id"`
+	KartId       int `json:"kart_id"`
+}
+
+type RaceResult struct {
+	ProfileID     uint32
+	PlayerID      int
+	FinishTime    uint32
+	CharacterID   uint32
+	VehicleID     uint32
+	PlayerCount   uint32
+	FinishPos     int
+	CourseID      int
+	EngineClassID int
+	Delta         int
+}
+
+var raceResults = map[string]map[int][]RaceResult{} // GroupName -> RaceNumber -> []RaceResult
+
 var groups = map[string]*Group{}
 
 func processResvOK(moduleName string, matchVersion int, reservation common.MatchCommandDataReservation, resvOK common.MatchCommandDataResvOK, sender, destination *Session) bool {
@@ -525,6 +549,91 @@ func ProcessMKWSelectRecord(profileId uint32, key string, value string) {
 
 }
 
+func ProcessMKWRaceResult(profileId uint32, playerPid int, finishTimeMs int, characterId int, kartId int) {
+	moduleName := "QR2:MKWRaceResult:" + strconv.FormatUint(uint64(profileId), 10)
+
+	mutex.Lock()
+	login := logins[profileId]
+	if login == nil {
+		mutex.Unlock()
+		logging.Warn(moduleName, "Received race result from non-existent profile ID", aurora.Cyan(profileId))
+		return
+	}
+
+	session := login.session
+	if session == nil {
+		mutex.Unlock()
+		logging.Warn(moduleName, "Received race result from profile ID", aurora.Cyan(profileId), "but no session exists")
+		return
+	}
+	mutex.Unlock()
+
+	group := session.groupPointer
+	if group == nil {
+		return
+	}
+
+	if group.MKWRaceNumber == 0 {
+		logging.Error(moduleName, "Received race result but no races have been started")
+		return
+	}
+
+	// Get the accumulated lag from race progress timing
+	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))
+	}
+
+	// Convert race result data to internal format
+	raceResultData := RaceResult{
+		ProfileID:     profileId,
+		PlayerID:      playerPid,
+		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
+		CourseID:      group.MKWCourseID,
+		EngineClassID: group.MKWEngineClassID,
+		Delta:         delta,
+	}
+
+	mutex.Lock()
+	defer mutex.Unlock()
+
+	if raceResults[group.GroupName] == nil {
+		raceResults[group.GroupName] = map[int][]RaceResult{}
+	}
+
+	raceResults[group.GroupName][group.MKWRaceNumber] = append(raceResults[group.GroupName][group.MKWRaceNumber], raceResultData)
+
+	logging.Info(moduleName, "Stored race result for profile", aurora.BrightCyan(strconv.FormatUint(uint64(profileId), 10)),
+		"Race #:", aurora.Cyan(strconv.Itoa(group.MKWRaceNumber)),
+		"Course:", aurora.Cyan(strconv.Itoa(group.MKWCourseID)),
+		"Delta:", aurora.Cyan(strconv.Itoa(delta)))
+}
+
+func GetRaceResultsForGroup(groupName string) map[int][]RaceResult {
+	mutex.Lock()
+	defer mutex.Unlock()
+
+	groupResults, ok := raceResults[groupName]
+	if !ok {
+		return nil
+	}
+
+	// Return a copy to prevent external modification
+	copiedRaceResults := make(map[int][]RaceResult)
+	for raceNumber, results := range groupResults {
+		copiedRaceResults[raceNumber] = make([]RaceResult, len(results))
+		copy(copiedRaceResults[raceNumber], results)
+	}
+
+	return copiedRaceResults
+}
+
 // saveGroups saves the current groups state to disk.
 // Expects the mutex to be locked.
 func saveGroups() error {

race/race_progress.go

@@ -0,0 +1,199 @@
+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)
+}