415 lines
14 KiB
Plaintext
415 lines
14 KiB
Plaintext
/* tws_telemetry.gsc - Electric Cherry game reports via t5-gsc-utils. */
|
|
|
|
#include maps\_utility;
|
|
#include common_scripts\utility;
|
|
|
|
init()
|
|
{
|
|
if (GetDvar(#"zombiemode") != "1")
|
|
return;
|
|
|
|
scripts\sp\tws_common::ensure_config();
|
|
|
|
if (GetDvar("tws_telemetry_enabled") == "0")
|
|
{
|
|
print("[tws_telemetry] Disabled by tws_telemetry_enabled=0");
|
|
return;
|
|
}
|
|
|
|
if (isDefined(level.telemetry_initialized))
|
|
return;
|
|
|
|
level.telemetry_url = GetDvar("tws_telemetry_url");
|
|
if (level.telemetry_url == "")
|
|
level.telemetry_url = "http://192.168.1.199:3000/api/telemetry";
|
|
|
|
level.telemetry_server = GetDvar("tws_server_id");
|
|
if (level.telemetry_server == "")
|
|
{
|
|
print("^1[tws_telemetry] Set tws_server_id to the registered Electric Cherry server name");
|
|
return;
|
|
}
|
|
|
|
level.telemetry_initialized = true;
|
|
level.telemetry_started = false;
|
|
level.telemetry_ended = false;
|
|
level.telemetry_last_round = -1;
|
|
level.telemetry_queue = [];
|
|
level.telemetry_queue_read = 0;
|
|
level.telemetry_queue_write = 0;
|
|
level.telemetry_sequence = 0;
|
|
level.telemetry_completed = 0;
|
|
level.telemetry_failed = 0;
|
|
level.telemetry_failure_streak = 0;
|
|
level.telemetry_last_completed = -1;
|
|
level.telemetry_last_capture = getTime();
|
|
level.telemetry_round_tick = getTime();
|
|
level.telemetry_capture_event = "none";
|
|
level.telemetry_sender_state = "starting";
|
|
level.telemetry_inflight = undefined;
|
|
|
|
telemetry_log(1, "Initialized; waiting for match start. log_level=" + telemetry_log_level());
|
|
|
|
// Use the shared dispatcher; a second connected listener breaks T5 SP.
|
|
scripts\sp\tws_common::register_spawn_handler(::telemetry_game_start);
|
|
|
|
level thread telemetry_game_end_watcher();
|
|
level thread telemetry_sender();
|
|
level thread telemetry_round_watcher();
|
|
level thread telemetry_watchdog();
|
|
}
|
|
|
|
// First playable spawn starts the match, including maps with a round-0 intro.
|
|
// Later spawns and joins must not reopen the match or repeat game_start.
|
|
telemetry_game_start()
|
|
{
|
|
if (level.telemetry_started || level.telemetry_ended)
|
|
return;
|
|
|
|
level.telemetry_started = true;
|
|
level.telemetry_last_capture = getTime();
|
|
telemetry_log(1, "Match start detected");
|
|
telemetry_enqueue("game_start");
|
|
level thread telemetry_heartbeat_watcher();
|
|
}
|
|
|
|
// Start the interval with the match, independently of round changes or joins.
|
|
telemetry_heartbeat_watcher()
|
|
{
|
|
level endon("telemetry_finished");
|
|
|
|
for (;;)
|
|
{
|
|
wait (30);
|
|
telemetry_report_round();
|
|
telemetry_enqueue("heartbeat");
|
|
}
|
|
}
|
|
|
|
// Independent of HUD installation and player count. begin_spawning also
|
|
// catches a start whose spawn predates our dispatcher, or has no players.
|
|
telemetry_round_watcher()
|
|
{
|
|
level endon("telemetry_finished");
|
|
|
|
for (;;)
|
|
{
|
|
level.telemetry_round_tick = getTime();
|
|
if (!level.telemetry_started && isDefined(level.flag) &&
|
|
isDefined(level.flag["begin_spawning"]) && level.flag["begin_spawning"])
|
|
{
|
|
telemetry_log(1, "Starting from begin_spawning fallback");
|
|
telemetry_game_start();
|
|
}
|
|
|
|
telemetry_report_round();
|
|
wait (0.5);
|
|
}
|
|
}
|
|
|
|
telemetry_report_round()
|
|
{
|
|
if (!level.telemetry_started || level.telemetry_ended ||
|
|
!isDefined(level.round_number) || level.round_number < 0)
|
|
return;
|
|
|
|
round = telemetry_nonnegative_int(level.round_number);
|
|
if (round == level.telemetry_last_round)
|
|
return;
|
|
|
|
level.telemetry_last_round = round;
|
|
telemetry_enqueue("round_change");
|
|
}
|
|
|
|
telemetry_game_end_watcher()
|
|
{
|
|
// One waiter consumes the first end signal, even if a map fires all three.
|
|
level waittill_any("end_game", "game_ended", "intermission");
|
|
telemetry_log(1, "Game-end signal received; stopping producers and draining queue");
|
|
|
|
// Preserve order even if the match ends before the next polling tick.
|
|
telemetry_game_start();
|
|
telemetry_report_round();
|
|
level.telemetry_ended = true;
|
|
level notify("telemetry_finished");
|
|
telemetry_enqueue("game_end");
|
|
}
|
|
|
|
telemetry_nonnegative_int(value)
|
|
{
|
|
if (!isDefined(value) || value < 0)
|
|
return 0;
|
|
|
|
return int(value);
|
|
}
|
|
|
|
telemetry_stat(player, name)
|
|
{
|
|
if (!isDefined(player.stats) || !isDefined(player.stats[name]))
|
|
return 0;
|
|
|
|
return telemetry_nonnegative_int(player.stats[name]);
|
|
}
|
|
|
|
telemetry_players_json(include_stats)
|
|
{
|
|
players = getPlayers();
|
|
body = "[";
|
|
|
|
for (i = 0; i < players.size; i++)
|
|
{
|
|
player = players[i];
|
|
if (!isDefined(player))
|
|
{
|
|
telemetry_log(0, "WARNING: skipping undefined player at roster index " + i);
|
|
continue;
|
|
}
|
|
|
|
data = [];
|
|
if (isDefined(player.name))
|
|
data["name"] = "" + player.name;
|
|
else if (isDefined(player.playername))
|
|
data["name"] = "" + player.playername;
|
|
else
|
|
{
|
|
telemetry_log(0, "WARNING: skipping player without a name at roster index " + i);
|
|
continue;
|
|
}
|
|
|
|
// getGuid returns a string. Never pass it through int or float.
|
|
guid = player getGuid();
|
|
if (!isDefined(guid) || guid == "" || data["name"] == "")
|
|
{
|
|
telemetry_log(0, "WARNING: skipping player with incomplete identity at roster index " + i);
|
|
continue;
|
|
}
|
|
data["guid"] = "" + guid;
|
|
|
|
if (include_stats)
|
|
{
|
|
data["kills"] = telemetry_stat(player, "kills");
|
|
data["headshots"] = telemetry_stat(player, "headshots");
|
|
data["downs"] = telemetry_stat(player, "downs");
|
|
data["revives"] = telemetry_stat(player, "revives");
|
|
// Current spendable points, not the lifetime points-earned stat.
|
|
data["score"] = telemetry_nonnegative_int(player.score);
|
|
}
|
|
|
|
if (body != "[")
|
|
body += ",";
|
|
body += jsonSerialize(data);
|
|
}
|
|
|
|
// t5-gsc-utils serializes an empty GSC array as null. Build only the
|
|
// array delimiters ourselves; the serializer still escapes all strings.
|
|
return body + "]";
|
|
}
|
|
|
|
telemetry_enqueue(event_name)
|
|
{
|
|
level.telemetry_capture_event = event_name;
|
|
telemetry_log(2, "Capturing event=" + event_name);
|
|
// Snapshot and serialize before yielding, including during game over.
|
|
body = "{\"event\":" + jsonSerialize(event_name);
|
|
body += ",\"server\":" + jsonSerialize(level.telemetry_server);
|
|
body += ",\"map\":" + jsonSerialize(GetDvar("mapname"));
|
|
if (event_name != "game_start")
|
|
body += ",\"round\":" + telemetry_nonnegative_int(level.round_number);
|
|
body += ",\"players\":" + telemetry_players_json(event_name != "game_start") + "}";
|
|
|
|
entry = [];
|
|
level.telemetry_sequence++;
|
|
entry["id"] = level.telemetry_sequence;
|
|
entry["event"] = event_name;
|
|
entry["round"] = telemetry_nonnegative_int(level.round_number);
|
|
entry["captured"] = getTime();
|
|
entry["body"] = body;
|
|
level.telemetry_queue[level.telemetry_queue_write] = entry;
|
|
level.telemetry_queue_write++;
|
|
level.telemetry_last_capture = getTime();
|
|
level.telemetry_capture_event = "none";
|
|
telemetry_log(2, "Queued " + telemetry_event_label(entry) + " pending=" + telemetry_pending());
|
|
level notify("telemetry_queued");
|
|
}
|
|
|
|
// A single worker keeps one request in flight. It survives game-over notifies
|
|
// to drain the final snapshot; no retries, discovery, or beta-specific calls.
|
|
telemetry_sender()
|
|
{
|
|
for (;;)
|
|
{
|
|
if (level.telemetry_queue_read == level.telemetry_queue_write)
|
|
{
|
|
level.telemetry_queue = [];
|
|
level.telemetry_queue_read = 0;
|
|
level.telemetry_queue_write = 0;
|
|
if (level.telemetry_ended)
|
|
{
|
|
level.telemetry_sender_state = "drained";
|
|
telemetry_log(1, "Queue drained after game end; completed=" + level.telemetry_completed + " failed=" + level.telemetry_failed);
|
|
level notify("telemetry_drained");
|
|
return;
|
|
}
|
|
|
|
level.telemetry_sender_state = "idle";
|
|
level waittill("telemetry_queued");
|
|
continue;
|
|
}
|
|
|
|
entry = level.telemetry_queue[level.telemetry_queue_read];
|
|
level.telemetry_queue[level.telemetry_queue_read] = undefined;
|
|
level.telemetry_queue_read++;
|
|
telemetry_send(entry);
|
|
}
|
|
}
|
|
|
|
telemetry_send(entry)
|
|
{
|
|
level.telemetry_inflight = entry;
|
|
level.telemetry_request_started = getTime();
|
|
level.telemetry_sender_state = "creating_request";
|
|
label = telemetry_event_label(entry);
|
|
telemetry_log(1, "Sending " + label + " queue_ms=" + (getTime() - entry["captured"]) + " pending=" + telemetry_pending());
|
|
|
|
headers = [];
|
|
headers["Content-Type"] = "application/json";
|
|
|
|
options = [];
|
|
options["method"] = "POST";
|
|
options["headers"] = headers;
|
|
options["body"] = entry["body"];
|
|
|
|
request = http::request(level.telemetry_url, options);
|
|
if (!isDefined(request))
|
|
{
|
|
telemetry_transport_failed(label + " request handle is undefined; skipping event");
|
|
level.telemetry_inflight = undefined;
|
|
level.telemetry_sender_state = "idle";
|
|
return;
|
|
}
|
|
|
|
level.telemetry_sender_state = "waiting_http";
|
|
request waittill("done", response, success, error);
|
|
elapsed = getTime() - level.telemetry_request_started;
|
|
level.telemetry_last_completed = getTime();
|
|
|
|
// The plugin's success flag reports transport completion, not HTTP status.
|
|
// No automatic retry: the receiver may already have accepted the event.
|
|
if (!isDefined(success) || !success)
|
|
{
|
|
if (!isDefined(error))
|
|
error = "unknown transport error";
|
|
telemetry_transport_failed(label + " elapsed_ms=" + elapsed + " error=" + telemetry_preview(error));
|
|
}
|
|
else
|
|
{
|
|
level.telemetry_completed++;
|
|
if (level.telemetry_failure_streak > 0)
|
|
telemetry_log(0, "Transport recovered after " + level.telemetry_failure_streak + " failures; " + label);
|
|
level.telemetry_failure_streak = 0;
|
|
telemetry_log(1, "Transport completed " + label + " elapsed_ms=" + elapsed + " (API acceptance unverified)");
|
|
if (!isDefined(response) || response == "")
|
|
telemetry_log(0, "WARNING: empty API response for " + label);
|
|
else
|
|
telemetry_log(2, "Response " + label + " body=" + telemetry_preview(response));
|
|
}
|
|
|
|
level.telemetry_inflight = undefined;
|
|
level.telemetry_sender_state = "idle";
|
|
}
|
|
|
|
telemetry_transport_failed(detail)
|
|
{
|
|
level.telemetry_failed++;
|
|
level.telemetry_failure_streak++;
|
|
telemetry_log(0, "ERROR: transport failed " + detail + " consecutive_failures=" + level.telemetry_failure_streak);
|
|
}
|
|
|
|
telemetry_pending()
|
|
{
|
|
return level.telemetry_queue_write - level.telemetry_queue_read;
|
|
}
|
|
|
|
telemetry_event_label(entry)
|
|
{
|
|
return "id=" + entry["id"] + " event=" + entry["event"] + " round=" + entry["round"];
|
|
}
|
|
|
|
// Read live so diagnostics can be increased without restarting the map.
|
|
telemetry_log_level()
|
|
{
|
|
raw = GetDvar("tws_telemetry_log_level");
|
|
if (raw == "0")
|
|
return 0;
|
|
if (raw == "2")
|
|
return 2;
|
|
return 1;
|
|
}
|
|
|
|
telemetry_log(verbosity, message)
|
|
{
|
|
if (verbosity > telemetry_log_level())
|
|
return;
|
|
|
|
print("[tws_telemetry] server=" + level.telemetry_server + " map=" + GetDvar("mapname") + " time_ms=" + getTime() + " " + message);
|
|
}
|
|
|
|
// Escape newlines/control characters and bound response/error output. Do not
|
|
// jsonParse arbitrary replies: a proxy may return HTML or malformed JSON.
|
|
telemetry_preview(value)
|
|
{
|
|
if (!isDefined(value))
|
|
return "<undefined>";
|
|
value = "" + value;
|
|
if (value.size > 256)
|
|
value = getSubStr(value, 0, 256) + "... [truncated]";
|
|
return jsonSerialize(value);
|
|
}
|
|
|
|
// Independent of producers and the HTTP wait; survives game over until drain.
|
|
// The plugin cannot cancel requests. Warn without opening overlapping POSTs
|
|
// that could arrive out of order or exhaust its native worker pool.
|
|
telemetry_watchdog()
|
|
{
|
|
level endon("telemetry_drained");
|
|
for (;;)
|
|
{
|
|
wait (30);
|
|
now = getTime();
|
|
pending = telemetry_pending();
|
|
completion_age = -1;
|
|
if (level.telemetry_last_completed >= 0)
|
|
completion_age = now - level.telemetry_last_completed;
|
|
|
|
telemetry_log(1, "Health started=" + level.telemetry_started + " ended=" + level.telemetry_ended +
|
|
" sender=" + level.telemetry_sender_state + " capturing=" + level.telemetry_capture_event +
|
|
" pending=" + pending + " queued_total=" + level.telemetry_sequence +
|
|
" completed=" + level.telemetry_completed + " failed=" + level.telemetry_failed +
|
|
" last_done_ms_ago=" + completion_age);
|
|
|
|
if (isDefined(level.telemetry_inflight))
|
|
{
|
|
age = now - level.telemetry_request_started;
|
|
if (age >= 30000)
|
|
telemetry_log(0, "WARNING: HTTP stalled " + telemetry_event_label(level.telemetry_inflight) +
|
|
" elapsed_ms=" + age + " pending=" + pending + " stage=" + level.telemetry_sender_state +
|
|
"; waiting for plugin completion (no cancellation API)");
|
|
}
|
|
else if (pending > 0)
|
|
{
|
|
oldest = level.telemetry_queue[level.telemetry_queue_read];
|
|
if (now - oldest["captured"] >= 30000)
|
|
telemetry_log(0, "WARNING: sender is not consuming queued reports; " + telemetry_event_label(oldest));
|
|
}
|
|
|
|
if (!level.telemetry_ended)
|
|
{
|
|
if (now - level.telemetry_round_tick > 5000)
|
|
telemetry_log(0, "WARNING: round watcher has stopped advancing");
|
|
if (level.telemetry_started && now - level.telemetry_last_capture >= 65000)
|
|
telemetry_log(0, "WARNING: no snapshot captured for " + (now - level.telemetry_last_capture) +
|
|
"ms; capture_event=" + level.telemetry_capture_event);
|
|
}
|
|
}
|
|
}
|