From 4ac1343b951fb2fd48d738785e38332f18fee46d Mon Sep 17 00:00:00 2001 From: AyeZeeBB Date: Mon, 12 Oct 2026 23:24:33 -0500 Subject: [PATCH] Crash reports: self-hosted Sentry instead of Backtrace, and opt-in performance timings Crash dumps now go to the project's own Sentry server. The launcher's out-of-process helper is unchanged; only where it posts and what it expects back are: - The default endpoint is the Sentry project's minidump URL. Report attributes travel as Sentry tags, with the release as reskate@. - An upload counts as accepted when the server answers with an event ID. - "backtrace" is "crash_report" throughout: the namespace, files, CMake targets, DINGOSDK_CRASH_REPORT_URL, DINGOSDK_BUILD_CRASH_REPORT_TESTS and the RESKATE_CRASH_REPORT_URL override. Performance timings are new, and off unless "Send performance timings" is ticked in the launcher's settings (RESKATE_TRACING=1). A small tracer (Engine/Core/Debug/trace.h) posts each finished step to Sentry as a transaction from a background thread; the launcher and the game it starts share one trace. Timed: the update check, the Steam download, Thunderstore installs, the mod merge, starting the game, the launch up to the first playable level, each level load, joining a session, fetching the identity lists, and the time spent in each level with its average frame rate and long frames. Turning crash reports off turns timings off too. --- CMakeLists.txt | 2 +- ...trace_tests.cpp => crash_report_tests.cpp} | 87 +++++-- Engine/Core/Debug/client.cpp | 8 +- .../Debug/{backtrace.h => crash_report.h} | 2 +- Engine/Core/Debug/multipart.cpp | 11 +- Engine/Core/Debug/multipart.h | 2 +- Engine/Core/Debug/native_dump.cpp | 2 +- Engine/Core/Debug/native_dump.h | 2 +- Engine/Core/Debug/protocol.h | 2 +- Engine/Core/Debug/trace.cpp | 228 ++++++++++++++++++ Engine/Core/Debug/trace.h | 65 +++++ Engine/Core/Debug/upload.cpp | 20 +- Engine/Core/Debug/upload.h | 2 +- Engine/Core/Log/crash.cpp | 6 +- Engine/Core/Log/logger.cpp | 15 +- Engine/Game/Multiplayer/session_model.h | 12 + Extension/Multiplayer/Session/session.cpp | 6 + .../Multiplayer/Session/session_commands.cpp | 17 +- .../Multiplayer/Session/session_internal.h | 3 + .../Multiplayer/Session/session_view.cpp | 1 + .../Steam/steam_server_browser.cpp | 6 +- .../Multiplayer/Steam/steam_server_browser.h | 1 + .../Multiplayer/developer_identity_fetch.cpp | 3 + Extension/UI/Overlay/hub_page.cpp | 10 +- Extension/UI/Overlay/multiplayer_lobbies.cpp | 10 +- Extension/World/level_loading.cpp | 40 +++ Launcher/crash_reporter.cpp | 6 +- Launcher/crash_reporter.h | 2 +- Launcher/gui_internal.h | 2 + Launcher/gui_launcher.cpp | 19 +- Launcher/gui_mods_browse.cpp | 4 + Launcher/gui_settings.cpp | 6 + Launcher/launch.cpp | 39 ++- Launcher/launch.h | 3 + Launcher/main.cpp | 5 +- Launcher/updater.cpp | 38 ++- README.md | 14 +- Runtime/frame_timing.cpp | 2 + cmake/Backtrace.cmake | 58 ----- cmake/CrashReport.cmake | 59 +++++ cmake/templates/backtrace_config.h.in | 5 - cmake/templates/crash_report_config.h.in | 5 + 42 files changed, 675 insertions(+), 155 deletions(-) rename Engine/Core/Debug/Test/{backtrace_tests.cpp => crash_report_tests.cpp} (74%) rename Engine/Core/Debug/{backtrace.h => crash_report.h} (92%) create mode 100644 Engine/Core/Debug/trace.cpp create mode 100644 Engine/Core/Debug/trace.h delete mode 100644 cmake/Backtrace.cmake create mode 100644 cmake/CrashReport.cmake delete mode 100644 cmake/templates/backtrace_config.h.in create mode 100644 cmake/templates/crash_report_config.h.in diff --git a/CMakeLists.txt b/CMakeLists.txt index 04b0c8e..4d6b98e 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -22,7 +22,7 @@ if(WIN32) endif() include(cmake/Apps.cmake) if(WIN32) - include(cmake/Backtrace.cmake) + include(cmake/CrashReport.cmake) endif() option(DINGOSDK_BUILD_TESTS "Build logging regression tests" OFF) diff --git a/Engine/Core/Debug/Test/backtrace_tests.cpp b/Engine/Core/Debug/Test/crash_report_tests.cpp similarity index 74% rename from Engine/Core/Debug/Test/backtrace_tests.cpp rename to Engine/Core/Debug/Test/crash_report_tests.cpp index 90f7f65..a77cb78 100644 --- a/Engine/Core/Debug/Test/backtrace_tests.cpp +++ b/Engine/Core/Debug/Test/crash_report_tests.cpp @@ -1,11 +1,12 @@ #include #include -#include "Engine/Core/Debug/backtrace.h" +#include "Engine/Core/Debug/crash_report.h" #include "Engine/Core/Debug/native_dump.h" #include "Engine/Core/Debug/upload.h" #include "Engine/Core/Debug/multipart.h" #include "Engine/Core/Debug/protocol.h" -#include "backtrace_config.h" +#include "Engine/Core/Debug/trace.h" +#include "crash_report_config.h" #include "Engine/Core/Log/logging.h" #include #include @@ -13,7 +14,7 @@ #include using namespace dingosdk; -using namespace dingosdk::backtrace; +using namespace dingosdk::crash_report; namespace { constexpr DWORD test_exception = 0xe0424242; void check(bool value, const char* message) { if (!value) throw std::runtime_error(message); } @@ -35,19 +36,53 @@ std::string read(const std::filesystem::path& path) { } void endpoint_checks() { Endpoint endpoint; - check(parse_endpoint(L"https://submit.backtrace.io/team/token/minidump", endpoint), "Hosted endpoint rejected"); - check(endpoint.host == L"submit.backtrace.io" && endpoint.port == 443 && endpoint.resource == L"/team/token/minidump", "Hosted URL components incorrect"); - check(parse_endpoint(L"https://team.sp.backtrace.io:6098/post?format=minidump&token=test", endpoint), "Listener endpoint rejected"); - check(endpoint.port == 6098 && endpoint.resource == L"/post?format=minidump&token=test", "Listener query lost"); + check(parse_endpoint(L"https://sentry.example.com/api/2/minidump/?sentry_key=0123abcd", endpoint), "Hosted endpoint rejected"); + check(endpoint.host == L"sentry.example.com" && endpoint.port == 443 && endpoint.resource == L"/api/2/minidump/?sentry_key=0123abcd", "Hosted URL components incorrect"); + check(parse_endpoint(L"https://sentry.example.com:9000/api/2/minidump/?sentry_key=0123abcd", endpoint), "Endpoint with a port rejected"); + check(endpoint.port == 9000 && endpoint.resource == L"/api/2/minidump/?sentry_key=0123abcd", "Endpoint port or key lost"); for (const auto* value : {L"", L"http://example.com/post", L"https://user:password@example.com/post", L"https://example.com/post#fragment", L"https://example.com/post\r\nheader", L"https:///post", L"https://example.com"}) check(!parse_endpoint(value, endpoint), "Unsafe endpoint accepted"); std::string id; - check(accepted_response(200, R"({"response":"ok","_rxid":"1234-abcd"})", id) && id == "1234-abcd", "Valid receipt rejected"); - for (const auto* response : {R"({"response":"error","_rxid":"1234"})", R"({"response":"ok"})", "OK", R"({"response":"ok","_rxid":"bad\nvalue"})"}) + const std::string receipt = "c350c4ee-5e2b-4b77-9b2e-5e4a2b0e1b9d"; + check(accepted_response(200, receipt + "\n", id) && id == receipt, "Valid receipt rejected"); + check(accepted_response(200, "c350c4ee5e2b4b779b2e5e4a2b0e1b9d", id), "Unhyphenated receipt rejected"); + for (const auto* response : {"", "\n", "OK", R"({"detail":"ok"})", "c350c4ee-5e2b-4b77-9b2e", "c350c4ee-5e2b-4b77-9b2e-5e4a2b0e1b9d-00"}) check(!accepted_response(200, response, id), "Unconfirmed submission accepted"); - check(!accepted_response(429, R"({"response":"ok","_rxid":"1234"})", id), "Rate limited submission accepted"); - check(!accepted_response(500, R"({"response":"ok","_rxid":"1234"})", id), "Failed submission accepted"); + check(!accepted_response(429, receipt, id), "Rate limited submission accepted"); + check(!accepted_response(500, receipt, id), "Failed submission accepted"); +} +void trace_checks() { + check(trace::envelope_url(L"https://sentry.example.com/api/2/minidump/?sentry_key=0123abcd") == + L"https://sentry.example.com/api/2/envelope/?sentry_key=0123abcd", "Envelope endpoint not derived from the minidump endpoint"); + check(trace::envelope_url(L"https://example.com/post").empty(), "Timings would be sent to an endpoint that is not Sentry's"); + trace::Transaction transaction; + transaction.name = "game.level_load"; transaction.operation = "app.load"; + transaction.trace_id = "0123456789abcdef0123456789abcdef"; transaction.release = "reskate@fixture-build"; + transaction.process = "Skate.exe"; transaction.ok = false; + transaction.finished = trace::Clock::now(); transaction.started = transaction.finished - std::chrono::milliseconds(1500); + transaction.tags = {{"destination", std::string(300, 'x')}}; + transaction.measurements = {{"fps_avg", 59.5}, {"worst_frame", 120.0, "millisecond"}}; + const auto wire = trace::envelope(transaction); + const auto first = wire.find('\n'), second = wire.find('\n', first + 1); + check(first != std::string::npos && second != std::string::npos && wire.back() == '\n', "Envelope is not three lines"); + const auto header = Json::parse(wire.substr(0, first)), item = Json::parse(wire.substr(first + 1, second - first - 1)); + const auto payload = wire.substr(second + 1, wire.size() - second - 2); + const auto event = Json::parse(payload); + check(item.at("type").string() == "transaction" && item.at("length").get() == payload.size(), "Envelope item header wrong"); + check(header.at("event_id").string() == event.at("event_id").string() && event.at("event_id").string().size() == 32, "Event ID missing"); + const auto& context = event.at("contexts").at("trace"); + check(context.at("trace_id").string() == transaction.trace_id && context.at("span_id").string().size() == 16 && + context.at("op").string() == "app.load" && context.at("status").string() == "internal_error", "Trace context wrong"); + check(event.at("transaction").string() == "game.level_load" && event.at("release").string() == "reskate@fixture-build" && + event.at("tags").at("process").string() == "Skate.exe" && event.at("tags").at("destination").string().size() == 200, "Transaction fields wrong"); + check(event.at("measurements").at("fps_avg").at("value").get() == 59.5 && + event.at("measurements").at("worst_frame").at("unit").string() == "millisecond", "Measurements wrong"); + check(event.at("start_timestamp").string() < event.at("timestamp").string() && event.at("timestamp").string().back() == 'Z', "Timestamps wrong"); + SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"0"); + check(!trace::start(), "Timings sent with crash reporting off"); + trace::frame(1000000000); + check(trace::take_frame_pacing().frames == 0, "Frame pacing counted while timings are off"); } void attachment_checks(const std::filesystem::path& root) { const auto directory = root / L"attachments"; @@ -87,7 +122,9 @@ void attachment_checks(const std::filesystem::path& root) { std::make_pair(header, wire.substr(end + 4, next - end - 4))).second, "Duplicate MIME field"); cursor = next + 2; } - check(parts.size() == 5 && parts.at("version").second == "fixture-build", "Attributes lost during multipart upload"); + const auto event = Json::parse(parts.at("sentry").second); + check(parts.size() == 4 && event.at("tags").at("version").string() == "fixture-build" && + event.at("release").string() == "reskate@fixture-build", "Attributes lost during multipart upload"); check(parts.at("upload_file_minidump").second == dump_bytes, "Dump bytes corrupted"); check(parts.at("attachment_ReSkate.log").second == original_log && parts.at("attachment_ReSkate.log").first.find("filename=\"ReSkate.log\"") != std::string::npos, "Log is not a named file attachment"); @@ -121,7 +158,7 @@ void queue_checks(const std::filesystem::path& root) { const Sender success = [](const auto&, const auto& queued_dump, const Json& attributes) { check(attributes.at("version").string() == "original-build", "Queued report lost original build attributes"); check(read(log_attachment_path(queued_dump)) == "original-session-log", "Retry lost original session log"); - return UploadResult{true, 200, 0, "1234-abcd"}; + return UploadResult{true, 200, 0, "c350c4ee5e2b4b779b2e5e4a2b0e1b9d"}; }; Handle lock(CreateFileW((queue / L"queue.lock").c_str(), GENERIC_WRITE, 0, nullptr, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr)); check(upload_pending(L"test", queue, success) == 0 && std::filesystem::exists(dump), "Queue lock failed"); @@ -172,7 +209,7 @@ void crash_check(const std::filesystem::path& root, bool native) { DWORD code{}; GetExitCodeProcess(child.value, &code); check(code == 42, "Previous exception handler was not preserved"); const auto log = read(root / L"ReSkate.log"); - check(log.find("Backtrace crash reporting enabled") != std::string::npos, "Helper did not start"); + check(log.find("Crash reporting enabled") != std::string::npos, "Helper did not start"); check((log.find("ReSkate unhandled exception") != std::string::npos) != native, "Fixture did not exercise the expected exception handler"); const auto queue = queue_directory(root / L"crashes", L"https://127.0.0.1:1/test/minidump"); std::filesystem::path dump; @@ -219,6 +256,15 @@ int wmain(int argc, wchar_t** argv) { << dump->exception_code << "; address 0x" << dump->exception_address << '\n'; return 0; } + if (argc == 2 && std::wstring_view(argv[1]) == L"--submit-trace") { + SetEnvironmentVariableW(L"RESKATE_TRACING", L"1"); + check(trace::start(), "Timings are not configured for this build"); + trace::record("integration.test", "test", std::chrono::milliseconds(1234), true, {{"integration.test", "true"}}, + {{"fps_avg", 60.0}}); + trace::flush(std::chrono::seconds(15)); + std::cout << "Sent one synthetic transaction named integration.test; look for it in Sentry.\n"; + return 0; + } if (argc == 3 && std::wstring_view(argv[1]) == L"--submit-fixture") { const std::filesystem::path dump(argv[2]); auto bytes = read(dump); @@ -230,12 +276,12 @@ int wmain(int argc, wchar_t** argv) { "Only synthetic regression-test crashes may be submitted by this command"); auto attributes = Json::parse(read(dump.wstring() + L".json")); attributes["integration.test"] = "true"; - attributes["error.message"] = "Synthetic ReSkate Backtrace integration test; no game crash"; - auto url = environment(L"RESKATE_BACKTRACE_URL"); + attributes["error.message"] = "Synthetic ReSkate crash report integration test; no game crash"; + auto url = environment(L"RESKATE_CRASH_REPORT_URL"); if (url.empty()) url = configured_url; const auto result = upload_report(url, dump, attributes); std::cout << "HTTP " << result.http_status << "; Windows error " << result.error << "; report " << result.report_id << '\n'; - check(result.accepted, "Backtrace did not confirm test report"); + check(result.accepted, "Sentry did not confirm test report"); return 0; } if (argc == 3 && (std::wstring_view(argv[1]) == L"--crash" || std::wstring_view(argv[1]) == L"--native-crash")) { @@ -247,7 +293,7 @@ int wmain(int argc, wchar_t** argv) { std::filesystem::create_directories(native_fixture_directory); } SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"1"); - SetEnvironmentVariableW(L"RESKATE_BACKTRACE_URL", L"https://127.0.0.1:1/test/minidump"); + SetEnvironmentVariableW(L"RESKATE_CRASH_REPORT_URL", L"https://127.0.0.1:1/test/minidump"); SetUnhandledExceptionFilter(finish_child); logging::Options options; options.directory = argv[2]; options.truncate_file = true; check(logging::initialize(options), "Fixture logging failed"); @@ -256,18 +302,19 @@ int wmain(int argc, wchar_t** argv) { return 3; } check(argc == 2, "Pass a fixture root"); + trace_checks(); const auto root = std::filesystem::path(argv[1]) / std::format(L"run-{}-{}", GetCurrentProcessId(), GetTickCount64()); std::filesystem::create_directories(root); SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"0"); check(start(root) == StartResult::disabled, "Explicit opt-out ignored"); SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"1"); - SetEnvironmentVariableW(L"RESKATE_BACKTRACE_URL", L"http://invalid/post"); + SetEnvironmentVariableW(L"RESKATE_CRASH_REPORT_URL", L"http://invalid/post"); check(start(root) == StartResult::failed, "Invalid endpoint enabled reporter"); endpoint_checks(); attachment_checks(root); queue_checks(root); crash_check(root / L"direct", false); crash_check(root / L"native", true); - std::cout << "Backtrace endpoint, receipts, multipart attachments, log snapshots, retries, retention, opt-out, exception chaining, direct capture and native-handler fallback checks passed.\n"; + std::cout << "Timing envelopes, endpoint, receipts, multipart attachments, log snapshots, retries, retention, opt-out, exception chaining, direct capture and native-handler fallback checks passed.\n"; } catch (const std::exception& error) { std::cerr << error.what() << '\n'; return 1; } } diff --git a/Engine/Core/Debug/client.cpp b/Engine/Core/Debug/client.cpp index a9adeea..cf7213d 100644 --- a/Engine/Core/Debug/client.cpp +++ b/Engine/Core/Debug/client.cpp @@ -1,11 +1,11 @@ -#include "backtrace.h" +#include "crash_report.h" #include "protocol.h" -#include "backtrace_config.h" +#include "crash_report_config.h" #include #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { namespace { std::array handles{}; HANDLE helper{}; @@ -27,7 +27,7 @@ StartResult start(const std::filesystem::path& log_directory) noexcept { try { if (report) return StartResult::ready; if (environment(L"RESKATE_CRASH_REPORTING") == L"0") return StartResult::disabled; - auto url = environment(L"RESKATE_BACKTRACE_URL"); + auto url = environment(L"RESKATE_CRASH_REPORT_URL"); if (url.empty()) url = configured_url; if (url.empty()) return StartResult::disabled; if (!url.starts_with(L"https://") || url.size() >= SharedReport{}.url.size()) return StartResult::failed; diff --git a/Engine/Core/Debug/backtrace.h b/Engine/Core/Debug/crash_report.h similarity index 92% rename from Engine/Core/Debug/backtrace.h rename to Engine/Core/Debug/crash_report.h index ad2df88..b36e46b 100644 --- a/Engine/Core/Debug/backtrace.h +++ b/Engine/Core/Debug/crash_report.h @@ -2,7 +2,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { enum class StartResult { disabled, ready, failed }; // Called outside DllMain. A missing endpoint or RESKATE_CRASH_REPORTING=0 disables reporting. StartResult start(const std::filesystem::path& log_directory) noexcept; diff --git a/Engine/Core/Debug/multipart.cpp b/Engine/Core/Debug/multipart.cpp index 3d17a3d..18727f1 100644 --- a/Engine/Core/Debug/multipart.cpp +++ b/Engine/Core/Debug/multipart.cpp @@ -4,7 +4,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { namespace { bool stream_file(HANDLE file, DWORD bytes, const std::function& sink) { std::array buffer{}; @@ -60,9 +60,14 @@ MultipartReport::MultipartReport(const std::filesystem::path& dump, const Json& !value.is_string() || value.string().size() > 4096 || value.string().find(boundary) != std::string::npos) { error_ = ERROR_INVALID_DATA; return; } - prefix_ += std::format("--{}\r\nContent-Disposition: form-data; name=\"{}\"\r\n\r\n{}\r\n", boundary, key, value.string()); - if (prefix_.size() > 65536) { error_ = ERROR_INVALID_DATA; return; } } + // Sentry reads event attributes from the "sentry" field; attributes become searchable tags. + Json event = Json::object(); + event["tags"] = attributes; + if (const auto version = attributes.value("version", ""); !version.empty()) event["release"] = "reskate@" + version; + const auto fields = event.dump(); + if (fields.size() > 65536 || fields.find(boundary) != std::string::npos) { error_ = ERROR_INVALID_DATA; return; } + prefix_ = std::format("--{}\r\nContent-Disposition: form-data; name=\"sentry\"\r\n\r\n{}\r\n", boundary, fields); prefix_ += std::format("--{}\r\nContent-Disposition: form-data; name=\"upload_file_minidump\"; filename=\"crash.dmp\"\r\nContent-Type: application/octet-stream\r\n\r\n", boundary); const auto metadata = attributes.dump(); if (metadata.size() > 65536) { error_ = ERROR_INVALID_DATA; return; } diff --git a/Engine/Core/Debug/multipart.h b/Engine/Core/Debug/multipart.h index 19fa1a0..63afbe8 100644 --- a/Engine/Core/Debug/multipart.h +++ b/Engine/Core/Debug/multipart.h @@ -4,7 +4,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { inline constexpr DWORD max_log_bytes = 8 * 1024 * 1024; enum class LogSnapshot { unavailable, complete, tail }; std::filesystem::path log_attachment_path(const std::filesystem::path& dump); diff --git a/Engine/Core/Debug/native_dump.cpp b/Engine/Core/Debug/native_dump.cpp index 3bc5500..64e97b6 100644 --- a/Engine/Core/Debug/native_dump.cpp +++ b/Engine/Core/Debug/native_dump.cpp @@ -5,7 +5,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { namespace { template bool read(std::span bytes, std::size_t offset, T& value) { if (offset > bytes.size() || sizeof(T) > bytes.size() - offset) return false; diff --git a/Engine/Core/Debug/native_dump.h b/Engine/Core/Debug/native_dump.h index fafe3cd..678cc3d 100644 --- a/Engine/Core/Debug/native_dump.h +++ b/Engine/Core/Debug/native_dump.h @@ -3,7 +3,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { struct NativeDump { std::filesystem::path path; DWORD process_id{}, process_created{}, thread_id{}, exception_code{}, timestamp{}; diff --git a/Engine/Core/Debug/protocol.h b/Engine/Core/Debug/protocol.h index 9be0be6..9de6dc2 100644 --- a/Engine/Core/Debug/protocol.h +++ b/Engine/Core/Debug/protocol.h @@ -3,7 +3,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { inline constexpr DWORD protocol_version = 2; inline constexpr DWORD capture_timeout_ms = 15000; struct SharedReport { diff --git a/Engine/Core/Debug/trace.cpp b/Engine/Core/Debug/trace.cpp new file mode 100644 index 0000000..56fc569 --- /dev/null +++ b/Engine/Core/Debug/trace.cpp @@ -0,0 +1,228 @@ +#include +#include +#include +#include "trace.h" +#include "protocol.h" +#include "crash_report_config.h" +#include "Engine/Core/Json/json.h" +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +namespace dingosdk::trace { +namespace { +constexpr std::size_t max_queued = 64; + +struct Internet { + HINTERNET value{}; + ~Internet() { if (value) WinHttpCloseHandle(value); } +}; +struct State { + std::mutex mutex; + std::condition_variable changed; + std::deque queue; + bool worker{}, sending{}; + bool enabled{}; + std::wstring host, resource; + INTERNET_PORT port{}; + std::string trace_id, process; +}; +std::string random_hex(std::size_t bytes) { + std::array buffer{}; + if (BCryptGenRandom(nullptr, buffer.data(), static_cast(bytes), BCRYPT_USE_SYSTEM_PREFERRED_RNG) < 0) + throw std::runtime_error("No random source"); + std::string text; + for (std::size_t i = 0; i < bytes; ++i) text += std::format("{:02x}", buffer[i]); + return text; +} +std::string narrow(std::wstring_view value) { + std::string result; + for (const auto c : value) result += c < 0x80 ? static_cast(c) : '?'; + return result; +} +std::string timestamp(Clock::time_point time) { + return std::format("{:%FT%T}Z", std::chrono::floor(time)); +} +void configure(State& s) { + using crash_report::environment; + if (environment(L"RESKATE_TRACING") != L"1" || environment(L"RESKATE_CRASH_REPORTING") == L"0") return; + auto url = environment(L"RESKATE_CRASH_REPORT_URL"); + if (url.empty()) url = crash_report::configured_url; + url = envelope_url(url); + URL_COMPONENTS parts{}; + parts.dwStructSize = sizeof(parts); + parts.dwHostNameLength = parts.dwUrlPathLength = parts.dwExtraInfoLength = static_cast(-1); + if (url.empty() || !WinHttpCrackUrl(url.c_str(), static_cast(url.size()), 0, &parts) || + parts.nScheme != INTERNET_SCHEME_HTTPS || !parts.dwHostNameLength) return; + s.host.assign(parts.lpszHostName, parts.dwHostNameLength); + s.resource.assign(parts.lpszUrlPath, parts.dwUrlPathLength); + if (parts.dwExtraInfoLength) s.resource.append(parts.lpszExtraInfo, parts.dwExtraInfoLength); + s.port = parts.nPort; + // The game inherits the launcher's trace, so one launch reads as one timeline. + s.trace_id = narrow(environment(L"RESKATE_TRACE_ID")); + if (s.trace_id.size() != 32 || s.trace_id.find_first_not_of("0123456789abcdef") != std::string::npos) { + s.trace_id = random_hex(16); + SetEnvironmentVariableW(L"RESKATE_TRACE_ID", std::wstring(s.trace_id.begin(), s.trace_id.end()).c_str()); + } + std::array path{}; + const auto length = GetModuleFileNameW(nullptr, path.data(), static_cast(path.size())); + if (length && length < path.size()) s.process = narrow(std::filesystem::path(path.data()).filename().wstring()); + s.enabled = true; +} +// Set by start() and never destroyed: the worker thread may outlive static +// destruction, and a DLL must not join a thread while the loader lock is held. +std::atomic active{}; +constexpr std::uint64_t hitch_ns = 50ull * 1000 * 1000; +struct Pacing { + std::atomic last{}, frames{}, total{}, hitches{}, worst{}; +} pacing; +void post(const State& s, const std::string& body) { + Internet session{WinHttpOpen(L"ReSkate-Trace/1", WINHTTP_ACCESS_TYPE_AUTOMATIC_PROXY, nullptr, nullptr, 0)}; + if (!session.value || !WinHttpSetTimeouts(session.value, 5000, 5000, 5000, 5000)) return; + Internet connection{WinHttpConnect(session.value, s.host.c_str(), s.port, 0)}; + if (!connection.value) return; + Internet request{WinHttpOpenRequest(connection.value, L"POST", s.resource.c_str(), nullptr, nullptr, + WINHTTP_DEFAULT_ACCEPT_TYPES, WINHTTP_FLAG_SECURE)}; + if (!request.value) return; + DWORD redirect = WINHTTP_OPTION_REDIRECT_POLICY_NEVER; + WinHttpSetOption(request.value, WINHTTP_OPTION_REDIRECT_POLICY, &redirect, sizeof(redirect)); + constexpr wchar_t headers[] = L"Content-Type: application/x-sentry-envelope\r\n"; + // A timing that cannot be delivered is dropped; nothing is retried or kept on disk. + if (WinHttpSendRequest(request.value, headers, static_cast(-1), const_cast(body.data()), + static_cast(body.size()), static_cast(body.size()), 0)) + WinHttpReceiveResponse(request.value, nullptr); +} +void work(State& s) noexcept { + std::unique_lock lock(s.mutex); + for (;;) { + s.changed.wait(lock, [&] { return !s.queue.empty(); }); + const auto body = std::move(s.queue.front()); + s.queue.pop_front(); + s.sending = true; + lock.unlock(); + try { post(s, body); } catch (...) {} + lock.lock(); + s.sending = false; + s.changed.notify_all(); + } +} +} +std::wstring envelope_url(std::wstring_view minidump_url) { + constexpr std::wstring_view minidump = L"/minidump/"; + const auto at = minidump_url.find(minidump); + if (at == std::wstring_view::npos) return {}; + return std::wstring(minidump_url.substr(0, at)) + L"/envelope/" + std::wstring(minidump_url.substr(at + minidump.size())); +} +std::string envelope(const Transaction& transaction) { + const auto event_id = random_hex(16); + Json trace = Json::object(); + trace["trace_id"] = transaction.trace_id; + trace["span_id"] = random_hex(8); + trace["op"] = transaction.operation; + trace["status"] = transaction.ok ? "ok" : "internal_error"; + Json contexts = Json::object(); + contexts["trace"] = trace; + Json info = Json::object(); + info["source"] = "custom"; + Json tags = Json::object(); + tags["process"] = transaction.process; + for (const auto& [key, value] : transaction.tags) tags[key] = value.substr(0, 200); + Json measurements = Json::object(); + for (const auto& measurement : transaction.measurements) { + Json entry = Json::object(); + entry["value"] = measurement.value; + entry["unit"] = measurement.unit; + measurements[measurement.name] = entry; + } + Json event = Json::object(); + event["type"] = "transaction"; + event["event_id"] = event_id; + event["platform"] = "native"; + event["transaction"] = transaction.name; + event["transaction_info"] = info; + event["start_timestamp"] = timestamp(transaction.started); + event["timestamp"] = timestamp(transaction.finished); + event["release"] = transaction.release; + event["contexts"] = contexts; + event["tags"] = tags; + if (!transaction.measurements.empty()) event["measurements"] = measurements; + event["spans"] = Json::array(); + Json header = Json::object(); + header["event_id"] = event_id; + header["sent_at"] = timestamp(Clock::now()); + const auto payload = event.dump(); + Json item = Json::object(); + item["type"] = "transaction"; + item["length"] = payload.size(); + return header.dump() + "\n" + item.dump() + "\n" + payload + "\n"; +} +bool start() noexcept { + try { + if (active.load()) return true; + auto s = std::make_unique(); + configure(*s); + if (!s->enabled) return false; + State* expected{}; + if (active.compare_exchange_strong(expected, s.get())) (void)s.release(); + return true; + } catch (...) { return false; } +} +void frame(std::uint64_t now_ns) noexcept { + if (!active.load(std::memory_order_relaxed)) return; + const auto previous = pacing.last.exchange(now_ns, std::memory_order_relaxed); + if (!previous || now_ns <= previous) return; + const auto took = now_ns - previous; + pacing.frames.fetch_add(1, std::memory_order_relaxed); + pacing.total.fetch_add(took, std::memory_order_relaxed); + if (took >= hitch_ns) pacing.hitches.fetch_add(1, std::memory_order_relaxed); + if (took > pacing.worst.load(std::memory_order_relaxed)) pacing.worst.store(took, std::memory_order_relaxed); +} +FramePacing take_frame_pacing() noexcept { + pacing.last.store(0, std::memory_order_relaxed); // the next frame starts a fresh interval + return {pacing.frames.exchange(0), pacing.total.exchange(0), pacing.hitches.exchange(0), pacing.worst.exchange(0)}; +} +void record(std::string_view name, std::string_view operation, std::chrono::milliseconds duration, + bool ok, Tags tags, Measurements measurements) noexcept { + try { + auto* const started = active.load(); + if (!started) return; + auto& s = *started; + Transaction transaction; + transaction.name = name; + transaction.operation = operation; + transaction.trace_id = s.trace_id; + transaction.release = std::string("reskate@") + crash_report::build_version; + transaction.process = s.process; + transaction.finished = Clock::now(); + transaction.started = transaction.finished - duration; + transaction.ok = ok; + transaction.tags = std::move(tags); + transaction.measurements = std::move(measurements); + auto body = envelope(transaction); + std::lock_guard lock(s.mutex); + if (s.queue.size() >= max_queued) return; + s.queue.push_back(std::move(body)); + if (!s.worker) { + std::thread([&s] { work(s); }).detach(); + s.worker = true; + } + s.changed.notify_all(); + } catch (...) {} +} +void flush(std::chrono::milliseconds timeout) noexcept { + try { + auto* const started = active.load(); + if (!started) return; + auto& s = *started; + std::unique_lock lock(s.mutex); + s.changed.wait_for(lock, timeout, [&] { return s.queue.empty() && !s.sending; }); + } catch (...) {} +} +} diff --git a/Engine/Core/Debug/trace.h b/Engine/Core/Debug/trace.h new file mode 100644 index 0000000..497c93a --- /dev/null +++ b/Engine/Core/Debug/trace.h @@ -0,0 +1,65 @@ +#pragma once +#include +#include +#include +#include +#include +#include +#include + +namespace dingosdk::trace { +using Tags = std::vector>; +using Clock = std::chrono::system_clock; +// A number carried by a transaction, such as an average frame rate. +struct Measurement { std::string name; double value{}; std::string unit{"none"}; }; +using Measurements = std::vector; +// Called once logging is up: true when this launch sends timings. Until then, +// and in programs that never call it, record() does nothing. Timings are off +// unless RESKATE_TRACING=1 (the launcher's "Send performance timings" setting), +// and off whenever crash reporting is (RESKATE_CRASH_REPORTING=0). +bool start() noexcept; +// Queues one finished operation as a Sentry transaction. Never waits on the +// network and never throws. A launch's launcher and game share one trace. +void record(std::string_view name, std::string_view operation, std::chrono::milliseconds duration, + bool ok = true, Tags tags = {}, Measurements measurements = {}) noexcept; +// Frame pacing between two takes: the game's frame hook feeds it, and the end +// of a level session takes it. A hitch is a frame of 50 ms or longer. +struct FramePacing { std::uint64_t frames{}, total_ns{}, hitches{}, worst_ns{}; }; +void frame(std::uint64_t now_ns) noexcept; +FramePacing take_frame_pacing() noexcept; +// Gives queued operations a moment to reach the server before the process exits. +void flush(std::chrono::milliseconds timeout) noexcept; + +// Times its own lifetime. An exception passing through marks the operation failed. +class Scope { +public: + Scope(std::string name, std::string operation) + : name_(std::move(name)), operation_(std::move(operation)) {} + ~Scope() { + record(name_, operation_, std::chrono::duration_cast( + std::chrono::steady_clock::now() - started_), ok_ && std::uncaught_exceptions() == exceptions_, std::move(tags_)); + } + Scope(const Scope&) = delete; + Scope& operator=(const Scope&) = delete; + void tag(std::string key, std::string value) { tags_.emplace_back(std::move(key), std::move(value)); } + void fail() noexcept { ok_ = false; } +private: + std::string name_, operation_; + Tags tags_; + std::chrono::steady_clock::time_point started_{std::chrono::steady_clock::now()}; + int exceptions_{std::uncaught_exceptions()}; + bool ok_{true}; +}; + +struct Transaction { + std::string name, operation, trace_id, release, process; + Clock::time_point started, finished; + bool ok{true}; + Tags tags; + Measurements measurements; +}; +// The Sentry envelope for one transaction: envelope header, item header, payload. +std::string envelope(const Transaction& transaction); +// The envelope endpoint beside a minidump endpoint, or empty when the URL is not one. +std::wstring envelope_url(std::wstring_view minidump_url); +} diff --git a/Engine/Core/Debug/upload.cpp b/Engine/Core/Debug/upload.cpp index 13f1917..24789d2 100644 --- a/Engine/Core/Debug/upload.cpp +++ b/Engine/Core/Debug/upload.cpp @@ -10,7 +10,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { namespace { struct Internet { HINTERNET value{}; @@ -54,14 +54,14 @@ bool parse_endpoint(const std::wstring& url, Endpoint& endpoint) { bool accepted_response(DWORD status, std::string_view response, std::string& report_id) { report_id.clear(); if (status < 200 || status >= 300) return false; - try { - const auto json = Json::parse(response, {65536, 8, 256}); - if (json.value("response", "") != "ok") return false; - const auto id = json.value("_rxid", ""); - if (id.empty() || id.size() > 128 || id.find_first_not_of("0123456789abcdefABCDEF-") != std::string::npos) return false; - report_id = id; - return true; - } catch (...) { return false; } + // Sentry's minidump endpoint answers with the event ID as plain text. + const auto first = response.find_first_not_of(" \t\r\n"), last = response.find_last_not_of(" \t\r\n"); + if (first == std::string_view::npos) return false; + const auto id = response.substr(first, last - first + 1); + if (id.size() > 36 || id.find_first_not_of("0123456789abcdefABCDEF-") != std::string_view::npos || + std::count_if(id.begin(), id.end(), [](char c) { return c != '-'; }) != 32) return false; + report_id = id; + return true; } std::filesystem::path queue_directory(const std::filesystem::path& root, const std::wstring& url) { // Hash the destination so changing projects cannot send an old queue to a new account. @@ -155,7 +155,7 @@ std::size_t upload_pending(const std::wstring& url, const std::filesystem::path& status_file(directory, std::format("Upload pending; HTTP {}; Windows error {}. Retrying on next launch.", result.http_status, result.error)); break; } - status_file(directory, "Accepted by Backtrace: " + result.report_id); + status_file(directory, "Accepted by Sentry: " + result.report_id); remove_report(entry.path()); if (++uploaded == 4) break; // Bound work for a single launch. } diff --git a/Engine/Core/Debug/upload.h b/Engine/Core/Debug/upload.h index ad1adaa..d59f188 100644 --- a/Engine/Core/Debug/upload.h +++ b/Engine/Core/Debug/upload.h @@ -5,7 +5,7 @@ #include #include -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { inline constexpr std::uintmax_t max_dump_bytes = 128ull * 1024 * 1024; inline constexpr std::size_t max_pending_reports = 20; struct Endpoint { std::wstring host, resource; USHORT port{}; }; diff --git a/Engine/Core/Log/crash.cpp b/Engine/Core/Log/crash.cpp index 3aeb6ae..36f3e7c 100644 --- a/Engine/Core/Log/crash.cpp +++ b/Engine/Core/Log/crash.cpp @@ -1,5 +1,5 @@ #include "logging_internal.h" -#include "Engine/Core/Debug/backtrace.h" +#include "Engine/Core/Debug/crash_report.h" #include namespace dingosdk::logging::detail { @@ -37,7 +37,7 @@ LONG WINAPI unhandled(EXCEPTION_POINTERS* exception) { FlushFileBuffers(file); CloseHandle(file); } } - backtrace::capture(exception); + crash_report::capture(exception); return previous ? previous(exception) : EXCEPTION_CONTINUE_SEARCH; } } @@ -56,6 +56,6 @@ void remove_crash_report() noexcept { const auto current = SetUnhandledExceptionFilter(previous); if (current != unhandled) SetUnhandledExceptionFilter(current); installed = false; - backtrace::stop(); + crash_report::stop(); } } diff --git a/Engine/Core/Log/logger.cpp b/Engine/Core/Log/logger.cpp index ec8fceb..4744f1c 100644 --- a/Engine/Core/Log/logger.cpp +++ b/Engine/Core/Log/logger.cpp @@ -1,5 +1,6 @@ #include "logging_internal.h" -#include "Engine/Core/Debug/backtrace.h" +#include "Engine/Core/Debug/crash_report.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Core/Console/console_core.h" #include #include @@ -186,12 +187,14 @@ bool initialize(const Options& options) noexcept { } s.initialized = true; detail::install_crash_report(options.directory); - const auto reporter = backtrace::start(options.directory); - emit_locked(s, reporter == backtrace::StartResult::failed ? Level::warning : Level::info, + const auto reporter = crash_report::start(options.directory); + emit_locked(s, reporter == crash_report::StartResult::failed ? Level::warning : Level::info, Context::sdk, Channel::runtime, - reporter == backtrace::StartResult::ready ? "Backtrace crash reporting enabled." - : reporter == backtrace::StartResult::disabled ? "Backtrace crash reporting disabled." - : "Backtrace crash reporter could not start; local crash logging remains active."); + reporter == crash_report::StartResult::ready ? "Crash reporting enabled." + : reporter == crash_report::StartResult::disabled ? "Crash reporting disabled." + : "Crash reporter could not start; local crash logging remains active."); + if (trace::start()) + emit_locked(s, Level::info, Context::sdk, Channel::runtime, "Performance timings are sent for this launch."); return s.file_output.load(); } catch (...) { OutputDebugStringA("ReSkate logging initialization failed; debugger output remains available.\n"); diff --git a/Engine/Game/Multiplayer/session_model.h b/Engine/Game/Multiplayer/session_model.h index 27e45be..9898368 100644 --- a/Engine/Game/Multiplayer/session_model.h +++ b/Engine/Game/Multiplayer/session_model.h @@ -6,6 +6,7 @@ #include "tick_settings.h" #include "voice_settings.h" #include +#include #include #include #include @@ -91,6 +92,9 @@ struct MultiplayerHostPreferences { unsigned tps = multiplayer_default_tps; std::string lobby_name; }; +// The least time between two searches of the lobby and server lists, whoever asks: the +// browser's refresh, a page opening, the console. The browser counts it down. +inline constexpr std::uint64_t multiplayer_browse_interval_us = 10000000; // Session text chat. A message is UTF-8 without control characters, at most // this many bytes; the log keeps the most recent lines of the session. inline constexpr std::size_t multiplayer_chat_max_bytes = 200; @@ -282,6 +286,8 @@ struct MultiplayerModel { bool public_host{}, lobby_listed{}, lobby_searching{}, lobby_joining{}, lobby_searched{}; std::uint64_t public_lobby{}; // Verified public listing, never a private invitation. std::string lobby_status, browser_status = "Refresh to find public ReSkate lobbies."; + // When the lists may be searched again, on the steady clock in microseconds (browse_wait). + std::uint64_t browse_ready_us{}; std::vector lobbies; bool network_telemetry{}; unsigned prioritized_connections{}; @@ -293,6 +299,12 @@ struct MultiplayerModel { raw_sent_bytes{}; }; // Whether the player's role on the dedicated server they are on has one of its commands. +// Whole seconds until the lobby and server lists may be searched again; 0 when they may be now. +inline int browse_wait(const MultiplayerModel& model) noexcept { + const auto now = static_cast(std::chrono::duration_cast( + std::chrono::steady_clock::now().time_since_epoch()).count()); + return model.browse_ready_us > now ? static_cast((model.browse_ready_us - now + 999999) / 1000000) : 0; +} inline bool server_can(const MultiplayerModel& model, std::string_view command) noexcept { return model.dedicated && role_allows(model.server_all_commands, model.server_commands, command); } diff --git a/Extension/Multiplayer/Session/session.cpp b/Extension/Multiplayer/Session/session.cpp index 14b4ab6..1cd7b75 100644 --- a/Extension/Multiplayer/Session/session.cpp +++ b/Extension/Multiplayer/Session/session.cpp @@ -1,4 +1,5 @@ #include "session_internal.h" +#include "Engine/Core/Debug/trace.h" #include "Extension/Multiplayer/Hud/native_player_ui.h" #include "Extension/Multiplayer/Hud/native_indicators.h" #include "Extension/Multiplayer/Hud/native_party.h" @@ -70,6 +71,9 @@ void reset_peer(Session &s, std::size_t slot) { s.peers[slot] = {}; } void stop(Session &s, std::string reason) { + // A join that ends before the host's map was ready never got in. + if (s.mode == Mode::join && s.awaiting_map && !s.travelling && s.join_started) + trace::record("multiplayer.join", "app.join", std::chrono::milliseconds((now_us() - s.join_started) / 1000), false); s.voice.reset(); s.voice_policy = {}; s.tps = multiplayer_default_tps; @@ -787,6 +791,8 @@ bool prepare_join_map(Session &s, bool ready, std::string_view current, MapLoade s.status = "Host map loaded. Waiting for your skater..."; return false; } + if (!s.travelling && s.join_started) + trace::record("multiplayer.join", "app.join", std::chrono::milliseconds((now - s.join_started) / 1000)); s.awaiting_map = false; s.fetching_since = 0; fetching_map_flag.store(false, std::memory_order_relaxed); diff --git a/Extension/Multiplayer/Session/session_commands.cpp b/Extension/Multiplayer/Session/session_commands.cpp index a44cd16..52bca5b 100644 --- a/Extension/Multiplayer/Session/session_commands.cpp +++ b/Extension/Multiplayer/Session/session_commands.cpp @@ -54,6 +54,12 @@ void apply_guest_tools(Session &s, bool noclip, bool no_bail, bool boosts) { } } // namespace session_detail namespace { +// Whether the lists may be searched now; saying yes starts the wait for the next search. +bool take_browse(Session &s, std::uint64_t now) { + if (s.browsed && now - s.browsed < multiplayer_browse_interval_us) return false; + s.browsed = now; + return true; +} std::string edit_distances(Session &s, std::string_view argument) { if (s.mode != Mode::host) return "Only the lobby host can change TPS distances."; MultiplayerDistances value; @@ -867,9 +873,12 @@ std::string command(std::string_view action, std::string_view argument, std::str if (action == "browse") { if (!s.transport.open()) s.status = s.transport.status().detail; - else { - s.lobbies.refresh(now_us()); - s.servers.refresh(now_us()); + else if (const auto now = now_us(); take_browse(s, now)) { + s.lobbies.refresh(now); + s.servers.refresh(now); + } else { + const auto left = multiplayer_browse_interval_us - (now - s.browsed); + return "The server list can be refreshed again in " + std::to_string((left + 999999) / 1000000) + " s."; } publish(s); return s.lobbies.status().browser; @@ -907,7 +916,7 @@ std::string command(std::string_view action, std::string_view argument, std::str } // A friend on a server this game has not listed yet: only the list has its code. if (game_server_steam_id(id)) { - s.servers.refresh(now_us()); + if (const auto now = now_us(); take_browse(s, now)) s.servers.refresh(now); s.status = "That server is not in your server list yet. Open the server browser and join it there."; publish(s); return s.status; diff --git a/Extension/Multiplayer/Session/session_internal.h b/Extension/Multiplayer/Session/session_internal.h index 18413c8..a308fc4 100644 --- a/Extension/Multiplayer/Session/session_internal.h +++ b/Extension/Multiplayer/Session/session_internal.h @@ -223,6 +223,9 @@ struct Session { SteamTransport transport; SteamLobbies lobbies{make_steam_lobby_api(), [](std::uint64_t host) { return banned_host(host) || reskate_banned(host); }}; SteamServerBrowser servers; + // When the lobby and server lists were last searched. Every search in the game, asked for + // or automatic, waits multiplayer_browse_interval_us after it (take_browse). + std::uint64_t browsed{}; // Guest of a dedicated server: whether the roster lists us as an admin, // and the server's voice range from it. // On a dedicated server: what the player's role gives them (its permissions packet), and the diff --git a/Extension/Multiplayer/Session/session_view.cpp b/Extension/Multiplayer/Session/session_view.cpp index 1df386b..aad9a3d 100644 --- a/Extension/Multiplayer/Session/session_view.cpp +++ b/Extension/Multiplayer/Session/session_view.cpp @@ -290,6 +290,7 @@ void publish(Session &s, const NativeFrame *local) { view.lobby_searched = lobby.searched; view.lobby_status = lobby.hosting; view.browser_status = lobby.browser; + view.browse_ready_us = s.browsed ? s.browsed + multiplayer_browse_interval_us : 0; // Dedicated servers first: they are always up and never a stranger's own session. view.lobbies = s.servers.rows(); // Looked up as the list is shown: the team's list can arrive, or change, after a server was found. diff --git a/Extension/Multiplayer/Steam/steam_server_browser.cpp b/Extension/Multiplayer/Steam/steam_server_browser.cpp index 43dcfb6..99dac05 100644 --- a/Extension/Multiplayer/Steam/steam_server_browser.cpp +++ b/Extension/Multiplayer/Steam/steam_server_browser.cpp @@ -183,10 +183,8 @@ const MultiplayerLobby *SteamServerBrowser::find(std::uint64_t id) const { } void SteamServerBrowser::refresh(std::uint64_t now) { if (!api().open()) return; - // Steam stops answering a game that asks often (an empty list, for minutes): one search at a - // time, a quarter of a minute apart, and three quarters after one that came back empty. - // Opening or refreshing the browser sooner shows what the last search found. - if (started_ && (!searches_.empty() || now - started_ < (internet_listed_ ? 15000000 : 45000000))) return; + // How often this may run is the session's to say (multiplayer_browse_interval_us). A search + // still waiting on pings that never answer is dropped for the new one. servers_ = api().servers(); if (!servers_) return; release(); diff --git a/Extension/Multiplayer/Steam/steam_server_browser.h b/Extension/Multiplayer/Steam/steam_server_browser.h index ab5c7b4..d2aab5e 100644 --- a/Extension/Multiplayer/Steam/steam_server_browser.h +++ b/Extension/Multiplayer/Steam/steam_server_browser.h @@ -24,6 +24,7 @@ std::optional read_server_tags(std::string_view tags, std::uin class SteamServerBrowser { public: ~SteamServerBrowser(); + // Starts a new search, dropping one still running. The caller limits how often. void refresh(std::uint64_t now); void tick(std::uint64_t now); bool searching() const { return !searches_.empty(); } diff --git a/Extension/Multiplayer/developer_identity_fetch.cpp b/Extension/Multiplayer/developer_identity_fetch.cpp index 196aaa7..bea5577 100644 --- a/Extension/Multiplayer/developer_identity_fetch.cpp +++ b/Extension/Multiplayer/developer_identity_fetch.cpp @@ -1,6 +1,7 @@ #include "developer_identity.h" #include "word_lists.h" #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Vfs/https_download.h" #include #include @@ -20,8 +21,10 @@ void fetch() noexcept { bool ok{}; try { https::Download download; + trace::Scope timing("backend.identity_lists", "http.client"); const auto answer = https::get_text(std::wstring(identity_lists_url.begin(), identity_lists_url.end()), max_bytes, 10, L"ReSkate-Identity/1", &download); + if (!answer) timing.fail(); if (answer) { auto lists = parse_identity_lists(*answer); server_tokens_rule = parse_server_tokens_required(*answer); diff --git a/Extension/UI/Overlay/hub_page.cpp b/Extension/UI/Overlay/hub_page.cpp index dacd54e..92b1c9f 100644 --- a/Extension/UI/Overlay/hub_page.cpp +++ b/Extension/UI/Overlay/hub_page.cpp @@ -432,7 +432,9 @@ void browser_page(Ui &ui, ImVec2 a, ImVec2 z) { const auto &mp = ui.mp; const float u = ui.u, gap = 28 * u, bar = 96 * u, list_width = (z.x - a.x) * .62f; auto *draw = ui.draw; - if (!h.searched && !mp.lobby_searching) h.searched = true, queue_multiplayer_action("browse", ""); + // Refreshing waits out the game-wide limit (multiplayer_browse_interval_us); the button counts it down. + const int wait = browse_wait(mp); + if (!h.searched && !wait) h.searched = true, queue_multiplayer_action("browse", ""); bool changed{}; // ---- the bar: search, filters, refresh { @@ -459,11 +461,11 @@ void browser_page(Ui &ui, ImVec2 a, ImVec2 z) { if (chip("FRIENDS", h.friends_only)) h.friends_only = !h.friends_only, changed = true; if (chip("HIDE FULL", h.hide_full)) h.hide_full = !h.hide_full, changed = true; if (chip("MY MAP", h.same_map)) h.same_map = !h.same_map, changed = true; - if (button(ui, hash("refresh"), ImVec2(z.x - 420 * u, a.y), ImVec2(z.x, a.y + bar), mp.lobby_searching ? "SEARCHING..." : "REFRESH", - Look::sticky, !mp.lobby_searching)) + const auto refresh = wait ? "REFRESH IN " + std::to_string(wait) : std::string(mp.lobby_searching ? "SEARCHING..." : "REFRESH"); + if (button(ui, hash("refresh"), ImVec2(z.x - 420 * u, a.y), ImVec2(z.x, a.y + bar), refresh.c_str(), Look::sticky, !wait)) queue_multiplayer_action("browse", ""); } - if (ui.input && !h.typing && (ui.pad.buttons & ~h.pad_before & 0x4000) && !mp.lobby_searching) queue_multiplayer_action("browse", ""); // X / Square + if (ui.input && !h.typing && (ui.pad.buttons & ~h.pad_before & 0x4000) && !wait) queue_multiplayer_action("browse", ""); // X / Square if (ui.input && !h.typing && (ui.pad.buttons & ~h.pad_before & 0x8000)) h.sort = static_cast((static_cast(h.sort) + 1) % 3), changed = true; // Y / Triangle // F marks the chosen server as a favorite, or takes the mark away. if (ui.input && !h.typing && !h.code_mode && ImGui::IsKeyPressed(ImGuiKey_F, false)) diff --git a/Extension/UI/Overlay/multiplayer_lobbies.cpp b/Extension/UI/Overlay/multiplayer_lobbies.cpp index ea5a4f1..2ee2c02 100644 --- a/Extension/UI/Overlay/multiplayer_lobbies.cpp +++ b/Extension/UI/Overlay/multiplayer_lobbies.cpp @@ -277,13 +277,15 @@ void join_page(SkateMenu &menu, const Model &model, const CallbacksV3 &callbacks // Coming into view (the menu opening, or switching to this tab) fetches the // latest lobbies, so the list is never one left over from earlier. const int frame = ImGui::GetFrameCount(); - if (menu.multiplayer_lobbies_frame != frame - 1 && !mp.lobby_searching) send_console(menu, callbacks, "mp browse"); + // Refreshing waits out the game-wide limit (multiplayer_browse_interval_us); the button counts it down. + const int wait = browse_wait(mp); + if (menu.multiplayer_lobbies_frame != frame - 1 && !wait) send_console(menu, callbacks, "mp browse"); menu.multiplayer_lobbies_frame = frame; // Toolbar: search, sort, same-map filter and refresh on one row. const auto &style = ImGui::GetStyle(); constexpr std::array sorts{"Best match", "Most players", "Name", "Map"}; menu.multiplayer_lobby_sort = std::clamp(menu.multiplayer_lobby_sort, 0, static_cast(sorts.size()) - 1); - const char *refresh_label = mp.lobby_searching ? "Refreshing..." : "Refresh"; + const auto refresh_label = (wait ? "Refresh in " + std::to_string(wait) : std::string(mp.lobby_searching ? "Refreshing..." : "Refresh")) + "###refresh"; const float refresh_width = ImGui::CalcTextSize("Refreshing...").x + style.FramePadding.x * 2; const float sort_width = ImGui::CalcTextSize("Most players").x + style.FramePadding.x * 2 + ImGui::GetFrameHeight(); const float same_map_width = ImGui::GetFrameHeight() + style.ItemInnerSpacing.x + ImGui::CalcTextSize("Same map only").x; @@ -302,8 +304,8 @@ void join_page(SkateMenu &menu, const Model &model, const CallbacksV3 &callbacks if (ImGui::IsItemHovered()) ImGui::SetTooltip("Dedicated servers are always up and are not someone's own game."); ImGui::SameLine(); - ImGui::BeginDisabled(mp.lobby_searching || mp.lobby_joining); - if (ImGui::Button(refresh_label, ImVec2(refresh_width, 0))) + ImGui::BeginDisabled(wait || mp.lobby_joining); + if (ImGui::Button(refresh_label.c_str(), ImVec2(refresh_width, 0))) send_console(menu, callbacks, "mp browse"); ImGui::EndDisabled(); diff --git a/Extension/World/level_loading.cpp b/Extension/World/level_loading.cpp index 96dea18..e41c6d1 100644 --- a/Extension/World/level_loading.cpp +++ b/Extension/World/level_loading.cpp @@ -3,6 +3,7 @@ #include "Engine/Vfs/mod_catalog.h" #include "Engine/Core/Hooks/hooks.h" #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Core/Platform/memory.h" #include "Engine/Game/Build/supported_build.h" #include "Engine/Game/World/client_state.h" @@ -98,6 +99,42 @@ bool snapshot(std::uintptr_t client, Sample& s) { return read(client + 0xc4, after) && after == s.state && read(client, vt) && vt == o.base + addr::engine::client_vtable; } +std::chrono::milliseconds since_process_start() noexcept { + FILETIME created{}, exited{}, kernel{}, user{}, now{}; + if (!GetProcessTimes(GetCurrentProcess(), &created, &exited, &kernel, &user)) return {}; + GetSystemTimeAsFileTime(&now); + const auto ticks = [](const FILETIME& time) { return (static_cast(time.dwHighDateTime) << 32) | time.dwLowDateTime; }; + return std::chrono::milliseconds(ticks(now) > ticks(created) ? (ticks(now) - ticks(created)) / 10000 : 0); +} +// Timings for Sentry (Engine/Core/Debug/trace.h), from the same observations as the log: +// each load, the launch up to the first playable level, and the frame pacing of the time +// spent in a level. Called with the observer's lock held. +void trace_progress(const level_logging::Progress& progress, bool was_running, std::uint64_t started, std::uint64_t at) { + static std::uint64_t session_started{}; + static std::string session_destination; + if (!was_running && progress.running && session_started) { + // A new load ends the level before it. Short stays say nothing about its frame rate. + const auto pacing = trace::take_frame_pacing(); + const auto lasted = at >= session_started ? at - session_started : 0; + if (lasted >= 10000 && pacing.frames && pacing.total_ns) + trace::record("game.level_session", "app.session", std::chrono::milliseconds(lasted), true, + {{"destination", session_destination}}, + {{"fps_avg", static_cast(pacing.frames) * 1e9 / static_cast(pacing.total_ns)}, + {"hitches", static_cast(pacing.hitches)}, + {"worst_frame", static_cast(pacing.worst_ns) / 1e6, "millisecond"}}); + session_started = 0; + } + // A load that just reached a terminal state; "first" is the one behind the splash screen. + if (!was_running || progress.running || progress.started != started || at < started) return; + const bool active = progress.state == 13 || progress.state == 21; + trace::record("game.level_load", "app.load", std::chrono::milliseconds(at - started), active, + {{"destination", progress.destination}, {"first", progress.sequence == 1 ? "true" : "false"}}); + if (!active) return; + if (progress.sequence == 1) trace::record("game.boot", "app.start", since_process_start()); + (void)trace::take_frame_pacing(); + session_started = at; + session_destination = progress.destination; +} bool observe(std::uintptr_t client, unsigned next, unsigned previous, std::uint64_t at, bool exact) noexcept { auto& o = observer(); try { @@ -108,7 +145,10 @@ bool observe(std::uintptr_t client, unsigned next, unsigned previous, std::uint6 sample.at = at; sample.previous = previous; if (!snapshot(client, sample) || (exact && (next > 26 || previous > 26 || sample.state != next))) return false; + const auto was_running = o.progress.running; + const auto started = o.progress.started; o.progress.observe(sample, exact, &emit); + trace_progress(o.progress, was_running, started, sample.at); if (o.dropped.load() && !o.drops_reported) { o.drops_reported = true; emit(Level::warning, "Some level observations were skipped; recorded stage timings may be incomplete."); diff --git a/Launcher/crash_reporter.cpp b/Launcher/crash_reporter.cpp index ce18077..203ce7a 100644 --- a/Launcher/crash_reporter.cpp +++ b/Launcher/crash_reporter.cpp @@ -6,7 +6,7 @@ #include "Engine/Core/Debug/native_dump.h" #include "Engine/Core/Debug/multipart.h" #include "Engine/Game/Build/supported_build.h" -#include "backtrace_config.h" +#include "crash_report_config.h" #include #include #include @@ -14,7 +14,7 @@ namespace { using namespace dingosdk; -using namespace dingosdk::backtrace; +using namespace dingosdk::crash_report; std::string utf8(const wchar_t* text) { const auto size = WideCharToMultiByte(CP_UTF8, 0, text, -1, nullptr, 0, nullptr, nullptr); if (size <= 1) return {}; @@ -121,7 +121,7 @@ int run(int argc, wchar_t** argv) { return saved ? 0 : 4; } } -int dingosdk::backtrace::run_reporter(int argc, wchar_t** argv) noexcept { +int dingosdk::crash_report::run_reporter(int argc, wchar_t** argv) noexcept { SetErrorMode(SEM_FAILCRITICALERRORS | SEM_NOGPFAULTERRORBOX | SEM_NOOPENFILEERRORBOX); try { return run(argc, argv); } catch (...) { return 1; } } diff --git a/Launcher/crash_reporter.h b/Launcher/crash_reporter.h index 8e6a47f..165afab 100644 --- a/Launcher/crash_reporter.h +++ b/Launcher/crash_reporter.h @@ -1,5 +1,5 @@ #pragma once -namespace dingosdk::backtrace { +namespace dingosdk::crash_report { // Internal launcher mode, entered before game launch or logging initialization. int run_reporter(int argc, wchar_t** argv) noexcept; } diff --git a/Launcher/gui_internal.h b/Launcher/gui_internal.h index 8c763fe..596dc6c 100644 --- a/Launcher/gui_internal.h +++ b/Launcher/gui_internal.h @@ -191,6 +191,8 @@ struct Settings { bool updates{true}; // Off: a crash uploads nothing (RESKATE_CRASH_REPORTING=0 for the launcher and the game). bool crash_reports{true}; + // On: launches send how long their steps took (RESKATE_TRACING=1 for the launcher and the game). + bool performance_timings{}; std::string steam_username; // never the password bool steam_remember{true}; bool steam_prefer_code{}; diff --git a/Launcher/gui_launcher.cpp b/Launcher/gui_launcher.cpp index dbb924a..c9c63e5 100644 --- a/Launcher/gui_launcher.cpp +++ b/Launcher/gui_launcher.cpp @@ -4,6 +4,7 @@ #include "Engine/Core/Json/json.h" #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Vfs/mod_catalog.h" #include @@ -62,6 +63,7 @@ Settings load_settings(const fs::path& path) { settings.keep_open_after_launch = !json.value("close_on_launch", !settings.keep_open_after_launch); settings.updates = json.value("updates", settings.updates); settings.crash_reports = json.value("crash_reports", settings.crash_reports); + settings.performance_timings = json.value("performance_timings", settings.performance_timings); settings.steam_username = json.value("steam_username", std::string()); settings.steam_remember = json.value("steam_remember", settings.steam_remember); settings.steam_prefer_code = json.value("steam_prefer_code", settings.steam_prefer_code); @@ -87,6 +89,7 @@ void save_settings(const fs::path& path, const Settings& settings) { json["close_on_launch"] = !settings.keep_open_after_launch; json["updates"] = settings.updates; json["crash_reports"] = settings.crash_reports; + json["performance_timings"] = settings.performance_timings; json["steam_username"] = settings.steam_username; json["steam_remember"] = settings.steam_remember; json["steam_prefer_code"] = settings.steam_prefer_code; @@ -151,6 +154,7 @@ void Launcher::save() { // The game inherits the launcher's environment, so this reaches the next launch; the // launcher's own crash reporting follows the setting from its next start. SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", settings_.crash_reports ? nullptr : L"0"); + SetEnvironmentVariableW(L"RESKATE_TRACING", settings_.performance_timings ? L"1" : L"0"); } template void Launcher::start(Task task) { @@ -361,6 +365,8 @@ void Launcher::run_updates() { void Launcher::run_download(bool validate) { const auto config = this->config(); if (!config) return run_check(); + trace::Scope timing("launcher.game_download", "task"); + timing.tag("mode", validate ? "verify" : "download"); set(Phase::downloading, "Preparing Steam download", {}, 0); const auto depot_downloader = update::ensure_depot_downloader(config->depot_downloader, progress_for("DepotDownloader")); @@ -410,6 +416,7 @@ void Launcher::run_download(bool validate) { wipe(password_); } if (cancel_) { + timing.tag("cancelled", "true"); run_check(); std::lock_guard lock(mutex_); state_.detail = "Download cancelled. It will resume where it stopped."; @@ -419,6 +426,7 @@ void Launcher::run_download(bool validate) { set(Phase::ready, "Ready to skate", "Skate build installed."); return; } + timing.fail(); fail(std::format("The Steam download did not finish (exit code {}). {}", code, output.message)); } @@ -430,10 +438,14 @@ bool Launcher::run_mod_merge() { std::error_code error; if (!fs::is_directory(root / mods::mods_folder, error)) return true; set(Phase::merging, "Preparing mods", "Merging what is installed", 0); + trace::Scope timing("launcher.mod_merge", "task"); auto catalog = mods::load_catalog(root, [this](const mods::MergeProgress& progress) { set_progress(progress.step, progress.total ? static_cast(progress.done) / static_cast(progress.total) : -1.0f); }); + timing.tag("mods", std::to_string(catalog.mods.size())); + timing.tag("mods.excluded", std::to_string(catalog.excluded.size())); + if (!catalog.issue.empty()) timing.fail(); for (const auto& note : catalog.notes) logging::write(logging::Level::info, logging::Channel::launcher, note); for (const auto& warning : catalog.warnings) @@ -497,8 +509,11 @@ void apply_crash_report_setting() noexcept { const auto length = GetModuleFileNameW(nullptr, path.data(), static_cast(path.size())); if (!length || length >= path.size()) return; path.resize(length); - if (!detail::load_settings(std::filesystem::path(path).parent_path() / L"ReSkateLauncher.settings.json").crash_reports) - SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"0"); + const auto settings = detail::load_settings(std::filesystem::path(path).parent_path() / L"ReSkateLauncher.settings.json"); + if (!settings.crash_reports) SetEnvironmentVariableW(L"RESKATE_CRASH_REPORTING", L"0"); + // A RESKATE_TRACING already set (to test with, or to refuse) is left alone. + if (settings.performance_timings && !GetEnvironmentVariableW(L"RESKATE_TRACING", nullptr, 0)) + SetEnvironmentVariableW(L"RESKATE_TRACING", L"1"); } catch (...) {} } } // namespace dingosdk::launcher_gui diff --git a/Launcher/gui_mods_browse.cpp b/Launcher/gui_mods_browse.cpp index 2a25dda..d28d000 100644 --- a/Launcher/gui_mods_browse.cpp +++ b/Launcher/gui_mods_browse.cpp @@ -5,6 +5,7 @@ #include "updater.h" #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include #include @@ -157,6 +158,9 @@ std::string install_package(ModsPanel& panel, const fs::path& root, const ts::Pa ~Cleanup() { std::error_code ignored; fs::remove(archive, ignored); fs::remove(folder, ignored); } } cleanup{folder, archive}; + trace::Scope timing("launcher.mod_install", "task"); + timing.tag("package", package.full_name); + timing.tag("version", version.number); set_activity(panel, "Downloading " + package.title() + " v" + version.number + (version.file_size ? " (" + size_text(version.file_size) + ")" : std::string())); panel.progress = 0; diff --git a/Launcher/gui_settings.cpp b/Launcher/gui_settings.cpp index b434d23..7d91c25 100644 --- a/Launcher/gui_settings.cpp +++ b/Launcher/gui_settings.cpp @@ -452,6 +452,12 @@ void settings_window(Launcher& launcher, const Fonts& fonts, ImVec2 size, Ui& ui "When the launcher or Skate crashes, upload a crash dump and that session's log so the ReSkate " "developers can fix it. The launcher picks a change up when it next starts.", settings.crash_reports); + setting_check("Send performance timings", + "Send how long downloads, mod installs, the mod merge, level loads and joining a " + "session took, and each level's average frame rate, so slow spots can be found and fixed. Nothing " + "about your account is included. Needs crash reports on; the launcher picks a change up when it " + "next starts.", + settings.performance_timings); break; } ImGui::EndChild(); diff --git a/Launcher/launch.cpp b/Launcher/launch.cpp index b7c83ca..c52f354 100644 --- a/Launcher/launch.cpp +++ b/Launcher/launch.cpp @@ -1,4 +1,5 @@ #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Core/Platform/launcher_support.h" #include "Engine/Vfs/initfs.h" #include "Engine/Vfs/content_cache_install.h" @@ -507,6 +508,33 @@ void relaunch(const fs::path& self, const std::vector& arguments) CloseHandle(process.hProcess); } +bool under_wine() { + const auto ntdll = GetModuleHandleW(L"ntdll.dll"); + const auto kernel32 = GetModuleHandleW(L"kernel32.dll"); + return (ntdll && GetProcAddress(ntdll, "wine_get_version")) || + (kernel32 && GetProcAddress(kernel32, "wine_get_dos_file_name")); +} + +// MangoHud's Vulkan layer draws into every swapchain of a process it is on for, +// and the launcher's window crashes with it. The layer reads its switches from +// the Linux environment, which Wine fixes when the process starts, so turning it +// off takes a restart. start_game hands MangoHud back to the game. +bool relaunch_without_mangohud(const fs::path& self, const std::vector& arguments) { + if (!under_wine()) return false; + if (GetEnvironmentVariableW(L"RESKATE_MANGOHUD_HELD", nullptr, 0)) { + logging::write(logging::Level::info, logging::Channel::launcher, + "MangoHud is off for the launcher window; the game still gets it."); + return false; + } + wchar_t enabled[8]{}; + const auto length = GetEnvironmentVariableW(L"MANGOHUD", enabled, 8); + if (length != 1 || enabled[0] != L'1' || GetEnvironmentVariableW(L"DISABLE_MANGOHUD", nullptr, 0)) return false; + set_environment(L"DISABLE_MANGOHUD", L"1"); + set_environment(L"RESKATE_MANGOHUD_HELD", L"1"); + relaunch(self, arguments); + return true; +} + std::wstring steam_offline_reason() { const auto pid = registry_dword(steam_process_key, L"pid"); if (!pid || !*pid) return L"no Steam client is registered as running (ActiveProcess pid is 0)"; @@ -584,10 +612,7 @@ void ensure_minidump_apiset_shim(const fs::path& game_directory) noexcept { // Windows resolves this API set itself. Only Wine/Proton needs a file // beside Skate.exe; copying a system DLL under an API-set name on // Windows creates an unnecessary executable that looks suspicious. - const auto ntdll = GetModuleHandleW(L"ntdll.dll"); - const auto kernel32 = GetModuleHandleW(L"kernel32.dll"); - if (!(ntdll && GetProcAddress(ntdll, "wine_get_version")) && - !(kernel32 && GetProcAddress(kernel32, "wine_get_dos_file_name"))) return; + if (!under_wine()) return; const auto shim = game_directory / L"api-ms-win-core-debug-minidump-l1-1-0.dll"; std::error_code ec; if (fs::exists(shim, ec)) return; @@ -608,6 +633,7 @@ void ensure_minidump_apiset_shim(const fs::path& game_directory) noexcept { DWORD start_game(const Session& session, const launcher::LaunchOptions& options, const std::function& created) { + trace::Scope timing("launcher.start_game", "app.start"); const auto& self = session.self; auto paths = session.paths; paths.game = canonical_file(paths.game, L"Skate.exe"); @@ -745,6 +771,11 @@ DWORD start_game(const Session& session, const launcher::LaunchOptions& options, command += mod_arguments; if (!mod_arguments.empty()) logging::write(logging::Level::info, logging::Channel::launcher, L"ModData folder detected; loading ModData/Default"); logging::write(logging::Level::info, logging::Channel::launcher, L"Child command: " + command); + if (GetEnvironmentVariableW(L"RESKATE_MANGOHUD_HELD", nullptr, 0)) { + // Held off for the launcher's own window only (relaunch_without_mangohud). + set_environment(L"DISABLE_MANGOHUD", nullptr); + set_environment(L"RESKATE_MANGOHUD_HELD", nullptr); + } std::vector command_buffer(command.begin(), command.end()); command_buffer.push_back(L'\0'); STARTUPINFOW startup{sizeof(startup)}; diff --git a/Launcher/launch.h b/Launcher/launch.h index 19f9149..15c2cb6 100644 --- a/Launcher/launch.h +++ b/Launcher/launch.h @@ -22,6 +22,9 @@ bool game_files_supported(const launcher::SiblingPaths& paths); // The config's depot/manifest ships the build this launcher was compiled for. bool config_matches_build(const launcher_update::Config& config); void relaunch(const std::filesystem::path& self, const std::vector& arguments); +// Under Wine/Proton with MangoHud on, restarts the launcher with MangoHud off for +// its own window and returns true. The game it starts still gets MangoHud. +bool relaunch_without_mangohud(const std::filesystem::path& self, const std::vector& arguments); // Steam's client process is running and signed in to an account. When it is // not, start_game runs the game in offline mode. bool steam_signed_in(); diff --git a/Launcher/main.cpp b/Launcher/main.cpp index b766ca9..5179d87 100644 --- a/Launcher/main.cpp +++ b/Launcher/main.cpp @@ -1,4 +1,5 @@ #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "crash_reporter.h" #include "gui.h" #include "launch.h" @@ -99,7 +100,7 @@ int WINAPI wWinMain(HINSTANCE, HINSTANCE, PWSTR, int) { return 1; } if (argc > 1 && std::wstring_view(argv[1]) == L"--reskate-crash-helper") { - const auto result = dingosdk::backtrace::run_reporter(argc, argv); + const auto result = dingosdk::crash_report::run_reporter(argc, argv); LocalFree(argv); return result; } @@ -118,6 +119,7 @@ int WINAPI wWinMain(HINSTANCE, HINSTANCE, PWSTR, int) { const auto session = app::open_session(log_level); logs = session.paths.logs; if (headless) run_headless(session, arguments, original); + else if (app::relaunch_without_mangohud(session.self, original)) dingosdk::logging::flush(); else result = dingosdk::launcher_gui::run(session, arguments); } catch (const std::exception& exception) { const auto message = widen(exception.what()); @@ -128,6 +130,7 @@ int WINAPI wWinMain(HINSTANCE, HINSTANCE, PWSTR, int) { MessageBoxW(nullptr, dialog.c_str(), L"ReSkate Launcher", MB_OK | MB_ICONERROR | MB_SETFOREGROUND); result = 1; } + dingosdk::trace::flush(std::chrono::seconds(3)); dingosdk::logging::shutdown(); return result; } diff --git a/Launcher/updater.cpp b/Launcher/updater.cpp index 8c72071..8e69f76 100644 --- a/Launcher/updater.cpp +++ b/Launcher/updater.cpp @@ -2,6 +2,7 @@ #include "Engine/Core/Json/json.h" #include "Engine/Core/Log/logging.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Core/Platform/launcher_support.h" #include "launcher_update_config.h" #include "text_encoding.h" @@ -298,6 +299,7 @@ std::optional fetch_config() { try { // Public releases: the newest release carries launcher.json and the files it pins. Only // this lookup uses GitHub's rate-limited API; the files come from the release's download links. + trace::Scope timing("launcher.update_check", "http.client"); const auto latest = std::wstring(L"https://api.github.com/repos/") + launcher_release_repo + L"/releases/latest"; logging::write(logging::Level::info, logging::Channel::launcher, L"Checking GitHub releases: " + std::wstring(launcher_release_repo)); std::string text; @@ -504,28 +506,48 @@ void replace_file(const fs::path& target, const RemoteFile& file, const Progress } } +namespace { + +constexpr int previous_launcher_names = 8; + +// ReSkateLauncher.exe.old, then .old1, .old2, ... +fs::path previous_launcher(const fs::path& self, int index) { + return self.wstring() + L".old" + (index ? std::to_wstring(index) : std::wstring{}); +} + +} // namespace + void replace_running_launcher(const fs::path& self, const RemoteFile& file, const Progress& progress) { const auto verified = download_verified(self, file, progress); - const fs::path previous = self.wstring() + L".old"; - DeleteFileW(previous.c_str()); - // Windows allows renaming, but not overwriting, a running executable. - if (!MoveFileExW(self.c_str(), previous.c_str(), MOVEFILE_WRITE_THROUGH)) { - const auto error = GetLastError(); + // Windows allows renaming, but not overwriting, a running executable. A .old that is still + // there belongs to a launcher that has not exited (or is held by antivirus) and cannot be + // deleted, so the next free name is used instead. + fs::path previous; + DWORD error = ERROR_ALREADY_EXISTS; + for (int index = 0; index < previous_launcher_names && error == ERROR_ALREADY_EXISTS; ++index) { + previous = previous_launcher(self, index); + DeleteFileW(previous.c_str()); + error = MoveFileExW(self.c_str(), previous.c_str(), MOVEFILE_WRITE_THROUGH) ? ERROR_SUCCESS : GetLastError(); + } + if (error != ERROR_SUCCESS) { DeleteFileW(verified.c_str()); fail(std::format("Cannot move the running launcher aside (Windows error {})", error)); } if (!MoveFileExW(verified.c_str(), self.c_str(), MOVEFILE_WRITE_THROUGH)) { - const auto error = GetLastError(); + error = GetLastError(); MoveFileExW(previous.c_str(), self.c_str(), MOVEFILE_WRITE_THROUGH); fail(std::format("Cannot install the launcher update (Windows error {})", error)); } } void remove_previous_launcher(const fs::path& self) noexcept { - const std::wstring previous = self.wstring() + L".old"; // The previous process may still be exiting; a later launch retries. for (int attempt = 0; attempt < 20; ++attempt) { - if (DeleteFileW(previous.c_str()) || GetLastError() == ERROR_FILE_NOT_FOUND) return; + bool remaining = false; + for (int index = 0; index < previous_launcher_names; ++index) + if (!DeleteFileW(previous_launcher(self, index).c_str()) && GetLastError() != ERROR_FILE_NOT_FOUND) + remaining = true; + if (!remaining) return; Sleep(100); } } diff --git a/README.md b/README.md index aa85a51..0ccc1e7 100644 --- a/README.md +++ b/README.md @@ -229,14 +229,14 @@ Useful launcher flags: | `DINGOSDK_VERSION` | `0.0.0` | version stamped into the binaries | | `DINGOSDK_LAUNCHER_AUTO_UPDATE` | `OFF` | let the launcher replace itself and `ReSkate.dll`, and the server replace itself (release builds) | | `DINGOSDK_RELEASE_REPO` | `Dingo-Shenanigans/ReSkate` | public GitHub repository whose latest release carries `launcher.json` and the files it pins | -| `DINGOSDK_BACKTRACE_URL` | the project's endpoint | Backtrace minidump submission URL; empty turns crash uploads off | +| `DINGOSDK_CRASH_REPORT_URL` | the project's endpoint | Sentry minidump endpoint URL; empty turns crash uploads off | | `DINGOSDK_TEST_GAME_ROOT` | empty | a Skate folder, for the tests that read real game data | ### Tests Each module keeps its regression tests in a `Test/` folder. Turn them on with any of `DINGOSDK_BUILD_MULTIPLAYER_TESTS`, `DINGOSDK_BUILD_LAUNCHER_TESTS`, `DINGOSDK_BUILD_PARK_EDITOR_TESTS` -and `DINGOSDK_BUILD_BACKTRACE_TESTS`, then run CTest: +and `DINGOSDK_BUILD_CRASH_REPORT_TESTS`, then run CTest: ```powershell cmake --preset vs2022-x64 -DDINGOSDK_BUILD_MULTIPLAYER_TESTS=ON -DDINGOSDK_BUILD_LAUNCHER_TESTS=ON @@ -278,10 +278,16 @@ bytes they expect before touching them, so code from the wrong build is refused ## Crash reports and privacy When the launcher or the game crashes, ReSkate uploads a minidump and that session's log to the -project's Backtrace account, so crashes can be fixed. The log never contains your Steam password or +project's self-hosted Sentry server, so crashes can be fixed. The log never contains your Steam password or login name. -To turn it off, untick **Send crash reports** in the launcher's Settings (ADVANCED), or set the +With **Send performance timings** ticked in the launcher's Settings (ADVANCED; off unless you turn it on), +ReSkate also sends how long a few steps took: the update check, the Steam download, mod +installs (with the package name), the mod merge, starting the game, each level load, joining a multiplayer +session and fetching the ReSkate lists. Time spent in a level adds its name, average frame rate and count of +long frames. Nothing about your account is included. Turning crash reports off turns this off too. + +To turn crash reports off, untick **Send crash reports** in the launcher's Settings (ADVANCED), or set the environment variable `RESKATE_CRASH_REPORTING=0`. ReSkate also keeps the game off EA's online services: the game's own crash reports, telemetry and diff --git a/Runtime/frame_timing.cpp b/Runtime/frame_timing.cpp index de46633..5ca11b8 100644 --- a/Runtime/frame_timing.cpp +++ b/Runtime/frame_timing.cpp @@ -1,4 +1,5 @@ #include "runtime_internal.h" +#include "Engine/Core/Debug/trace.h" #include "Engine/Core/Hooks/hooks.h" #include "Engine/Core/Profiling/profiler.h" #include "Engine/Game/Build/addresses.h" @@ -13,6 +14,7 @@ using ClientFrameJob = std::uintptr_t (*)(std::uintptr_t, std::uintptr_t, std::u ClientFrameJob original_client_frame_job{}; std::uintptr_t client_frame_job(std::uintptr_t job, std::uintptr_t timing, std::uintptr_t dependencies, std::uintptr_t extra) { const auto start = dingosdk::profiler::now_ns(); + dingosdk::trace::frame(start); // frame pacing for a level session's timing; a few atomic adds const auto result = original_client_frame_job(job, timing, dependencies, extra); dingosdk::profiler::record_client_frame(dingosdk::profiler::now_ns() - start); return result; diff --git a/cmake/Backtrace.cmake b/cmake/Backtrace.cmake deleted file mode 100644 index bc50fd6..0000000 --- a/cmake/Backtrace.cmake +++ /dev/null @@ -1,58 +0,0 @@ -# A submission token grants report submission only; never use an API/admin token. -set(backtrace_default_url "https://submit.backtrace.io/r5rlauncher/657dc750570e574383ec9d78548fed4c5d5061be3033d7adc064a4c6c28e058d/minidump") -if(NOT "$ENV{RESKATE_BACKTRACE_URL}" STREQUAL "") - set(backtrace_default_url "$ENV{RESKATE_BACKTRACE_URL}") -endif() -set(DINGOSDK_BACKTRACE_URL "${backtrace_default_url}" CACHE STRING "Backtrace HTTPS minidump submission URL (empty disables uploads)") -if(DINGOSDK_BACKTRACE_URL AND NOT DINGOSDK_BACKTRACE_URL MATCHES "^https://[^ \r\n\t]+$") - message(FATAL_ERROR "DINGOSDK_BACKTRACE_URL must be an HTTPS minidump submission URL") -endif() -set(backtrace_url_escaped "${DINGOSDK_BACKTRACE_URL}") -string(REPLACE "\\" "\\\\" backtrace_url_escaped "${backtrace_url_escaped}") -string(REPLACE "\"" "\\\"" backtrace_url_escaped "${backtrace_url_escaped}") -find_package(Git QUIET) -set(backtrace_version "unknown") -if(GIT_FOUND) - execute_process(COMMAND "${GIT_EXECUTABLE}" describe --always --dirty --abbrev=12 - WORKING_DIRECTORY "${PROJECT_SOURCE_DIR}" OUTPUT_VARIABLE backtrace_revision - OUTPUT_STRIP_TRAILING_WHITESPACE ERROR_QUIET) - if(backtrace_revision) - set(backtrace_version "${backtrace_revision}") - endif() -endif() -configure_file(cmake/templates/backtrace_config.h.in generated/backtrace_config.h @ONLY) - -add_library(dingosdk_backtrace_client STATIC Engine/Core/Debug/client.cpp) -add_library(dingosdk_backtrace_upload STATIC Engine/Core/Debug/upload.cpp - Engine/Core/Debug/native_dump.cpp Engine/Core/Debug/multipart.cpp) -target_link_libraries(dingosdk_backtrace_upload PRIVATE dingosdk_json winhttp bcrypt) -target_sources(dingosdk_launcher PRIVATE Launcher/crash_reporter.cpp) -target_link_libraries(dingosdk_launcher PRIVATE dingosdk_backtrace_upload dingosdk_json dbghelp) -target_link_libraries(dingosdk_logging PRIVATE dingosdk_backtrace_client) -# The launcher hosts crash capture for both executables; no third binary is shipped. -add_dependencies(dingosdk_runtime dingosdk_launcher) - -# Release dumps need matching symbols; keep optimization and omit incremental linking. -# PDBALTPATH embeds only the PDB's file name, not the build machine's folder. -foreach(target dingosdk_runtime dingosdk_launcher dingosdk_server) - target_compile_options(${target} PRIVATE /Zi) - target_link_options(${target} PRIVATE /DEBUG:FULL /INCREMENTAL:NO /OPT:REF /OPT:ICF - "/PDBALTPATH:$") -endforeach() -get_property(backtrace_targets DIRECTORY PROPERTY BUILDSYSTEM_TARGETS) -foreach(target IN LISTS backtrace_targets) - get_target_property(kind ${target} TYPE) - if(kind STREQUAL "STATIC_LIBRARY") - target_compile_options(${target} PRIVATE /Zi) - endif() -endforeach() - -option(DINGOSDK_BUILD_BACKTRACE_TESTS "Build crash capture and upload regression tests" OFF) -if(DINGOSDK_BUILD_BACKTRACE_TESTS) - enable_testing() - add_executable(dingosdk_backtrace_tests Engine/Core/Debug/Test/backtrace_tests.cpp) - target_link_libraries(dingosdk_backtrace_tests PRIVATE dingosdk_logging dingosdk_backtrace_upload dingosdk_json dbghelp) - add_dependencies(dingosdk_backtrace_tests dingosdk_launcher) - add_test(NAME backtrace COMMAND dingosdk_backtrace_tests "${CMAKE_CURRENT_BINARY_DIR}/backtrace-fixtures") - set_tests_properties(backtrace PROPERTIES TIMEOUT 90) -endif() diff --git a/cmake/CrashReport.cmake b/cmake/CrashReport.cmake new file mode 100644 index 0000000..359f9fa --- /dev/null +++ b/cmake/CrashReport.cmake @@ -0,0 +1,59 @@ +# The sentry_key is the project's public DSN key: it grants report submission only. Never use an auth token. +set(crash_report_default_url "https://sentry.reskate.dev/api/2/minidump/?sentry_key=8efcb389bdc033445093a7af0c66f9be") +if(NOT "$ENV{RESKATE_CRASH_REPORT_URL}" STREQUAL "") + set(crash_report_default_url "$ENV{RESKATE_CRASH_REPORT_URL}") +endif() +set(DINGOSDK_CRASH_REPORT_URL "${crash_report_default_url}" CACHE STRING "Sentry HTTPS minidump endpoint URL (empty disables uploads)") +if(DINGOSDK_CRASH_REPORT_URL AND NOT DINGOSDK_CRASH_REPORT_URL MATCHES "^https://[^ \r\n\t]+$") + message(FATAL_ERROR "DINGOSDK_CRASH_REPORT_URL must be an HTTPS minidump endpoint URL") +endif() +set(crash_report_url_escaped "${DINGOSDK_CRASH_REPORT_URL}") +string(REPLACE "\\" "\\\\" crash_report_url_escaped "${crash_report_url_escaped}") +string(REPLACE "\"" "\\\"" crash_report_url_escaped "${crash_report_url_escaped}") +find_package(Git QUIET) +set(crash_report_version "unknown") +if(GIT_FOUND) + execute_process(COMMAND "${GIT_EXECUTABLE}" describe --always --dirty --abbrev=12 + WORKING_DIRECTORY "${PROJECT_SOURCE_DIR}" OUTPUT_VARIABLE crash_report_revision + OUTPUT_STRIP_TRAILING_WHITESPACE ERROR_QUIET) + if(crash_report_revision) + set(crash_report_version "${crash_report_revision}") + endif() +endif() +configure_file(cmake/templates/crash_report_config.h.in generated/crash_report_config.h @ONLY) + +add_library(dingosdk_crash_report_client STATIC Engine/Core/Debug/client.cpp Engine/Core/Debug/trace.cpp) +target_link_libraries(dingosdk_crash_report_client PRIVATE dingosdk_json winhttp bcrypt) +add_library(dingosdk_crash_report_upload STATIC Engine/Core/Debug/upload.cpp + Engine/Core/Debug/native_dump.cpp Engine/Core/Debug/multipart.cpp) +target_link_libraries(dingosdk_crash_report_upload PRIVATE dingosdk_json winhttp bcrypt) +target_sources(dingosdk_launcher PRIVATE Launcher/crash_reporter.cpp) +target_link_libraries(dingosdk_launcher PRIVATE dingosdk_crash_report_upload dingosdk_json dbghelp) +target_link_libraries(dingosdk_logging PRIVATE dingosdk_crash_report_client) +# The launcher hosts crash capture for both executables; no third binary is shipped. +add_dependencies(dingosdk_runtime dingosdk_launcher) + +# Release dumps need matching symbols; keep optimization and omit incremental linking. +# PDBALTPATH embeds only the PDB's file name, not the build machine's folder. +foreach(target dingosdk_runtime dingosdk_launcher dingosdk_server) + target_compile_options(${target} PRIVATE /Zi) + target_link_options(${target} PRIVATE /DEBUG:FULL /INCREMENTAL:NO /OPT:REF /OPT:ICF + "/PDBALTPATH:$") +endforeach() +get_property(crash_report_targets DIRECTORY PROPERTY BUILDSYSTEM_TARGETS) +foreach(target IN LISTS crash_report_targets) + get_target_property(kind ${target} TYPE) + if(kind STREQUAL "STATIC_LIBRARY") + target_compile_options(${target} PRIVATE /Zi) + endif() +endforeach() + +option(DINGOSDK_BUILD_CRASH_REPORT_TESTS "Build crash capture and upload regression tests" OFF) +if(DINGOSDK_BUILD_CRASH_REPORT_TESTS) + enable_testing() + add_executable(dingosdk_crash_report_tests Engine/Core/Debug/Test/crash_report_tests.cpp) + target_link_libraries(dingosdk_crash_report_tests PRIVATE dingosdk_logging dingosdk_crash_report_upload dingosdk_json dbghelp) + add_dependencies(dingosdk_crash_report_tests dingosdk_launcher) + add_test(NAME crash_report COMMAND dingosdk_crash_report_tests "${CMAKE_CURRENT_BINARY_DIR}/crash-report-fixtures") + set_tests_properties(crash_report PROPERTIES TIMEOUT 90) +endif() diff --git a/cmake/templates/backtrace_config.h.in b/cmake/templates/backtrace_config.h.in deleted file mode 100644 index 44858bb..0000000 --- a/cmake/templates/backtrace_config.h.in +++ /dev/null @@ -1,5 +0,0 @@ -#pragma once -namespace dingosdk::backtrace { -inline constexpr wchar_t configured_url[] = L"@backtrace_url_escaped@"; -inline constexpr char build_version[] = "@backtrace_version@"; -} diff --git a/cmake/templates/crash_report_config.h.in b/cmake/templates/crash_report_config.h.in new file mode 100644 index 0000000..215594c --- /dev/null +++ b/cmake/templates/crash_report_config.h.in @@ -0,0 +1,5 @@ +#pragma once +namespace dingosdk::crash_report { +inline constexpr wchar_t configured_url[] = L"@crash_report_url_escaped@"; +inline constexpr char build_version[] = "@crash_report_version@"; +}