Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,11 @@

## Unreleased

- Add provider-neutral, layer-attributed JSONL diagnostics across the Racket
backend, C++/Swift native clients, transports, and embedding bridges. Records
identify lifecycle/RPC boundaries, status, last RVT1 event, and request id;
stderr defaults and injectable sinks keep logging dependencies out of the
runtime and leave the RVT1 wire contract unchanged.
- Launch packaged GUI artifacts as the final verification gate when a graphical
session is available. The executable starts from an unrelated temporary
directory, must remain alive for five seconds, and is then terminated;
Expand Down
55 changes: 55 additions & 0 deletions docs/diagnostics.md
Original file line number Diff line number Diff line change
Expand Up @@ -80,3 +80,58 @@ raco rivet build
```

For automated diagnostics, substitute `raco rivet doctor --json` and archive the resulting JSON with the failing build logs.

## Embedded runtime diagnostics

The embedded Windows, macOS, and Linux runtimes and the Racket backend emit one
JSON object per line for lifecycle and request-boundary events. This is separate
from RVT1: it does not add protocol frames, alter application payloads, or couple
the runtime to a logging provider.

```json
{"schema":"rivet.diagnostic.v1","layer":"native-client","event":"rpc-dispatch","status":"success","last_protocol_event":"response","request_id":42}
```

Every record contains:

- `schema`: always `rivet.diagnostic.v1`;
- `layer`: `native-runtime`, `abi-bridge`, `transport`, `protocol`,
`native-client`, or `racket-backend`;
- `event` and `status`: the lifecycle boundary and `begin`, `success`, or
`failure`;
- `last_protocol_event`: the most recently observed RVT1 message kind, or
`none` before the first frame;
- optional `request_id` and `message` fields.

The event stream covers backend initialization, transport creation, Hello
handshake, per-RPC dispatch, cancellation, orderly shutdown, unexpected channel
closure, reader-loop failure, and backend exit. A failure record therefore says
whether the last known boundary was the Racket backend, the ABI bridge, RVT1
validation, transport I/O, or the native client.

By default, embedded applications write JSONL to standard error. Applications
can redirect records to their own logger or crash reporter without adding a
Rivet logging dependency:

```cpp
rivet::windows::RacketRuntimeConfig config;
config.diagnostic_sink = [](rivet::DiagnosticRecord const& record) {
application_log(rivet::diagnostic_json_line(record));
};
```

The same `diagnostic_sink` field is available in the Linux runtime config. On
Apple platforms, pass `diagnosticSink:` to
`EmbeddedRacketConfiguration.resolvedDefault` or `RivetClient`. On the Racket
side, `serve-fds` uses `current-rivet-diagnostic-sink`; direct `serve` callers
can pass `#:diagnostic-sink` explicitly.

Diagnostic sinks run on runtime and request threads. They should be fast,
thread-safe, non-blocking, and must not call back into the same runtime. C++
sink exceptions are isolated from the application lifecycle.

Rivet never records RPC argument or result payloads. RPC begin records may name
the called API, and failure messages may contain application exception text;
treat the JSONL stream as operational log data and apply the same redaction and
retention policy as other crash reports. Racket-side messages are bounded to
4096 characters and avoid invoking custom printers on arbitrary raised values.
26 changes: 26 additions & 0 deletions platform/linux/Integration/main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include <iostream>
#include <iterator>
#include <memory>
#include <mutex>
#include <optional>
#include <stdexcept>
#include <string>
Expand Down Expand Up @@ -202,6 +203,27 @@ int main(int argc, char** argv) {
config.entry_symbol = "start";
config.max_pending_requests = 32;

std::mutex diagnostics_mutex;
std::vector<rivet::DiagnosticRecord> diagnostics;
config.diagnostic_sink = [&](rivet::DiagnosticRecord const& record) {
std::lock_guard lock(diagnostics_mutex);
diagnostics.push_back(record);
};

auto require_diagnostic = [&](std::string const& layer,
std::string const& event,
std::string const& status) {
std::lock_guard lock(diagnostics_mutex);
for (auto const& record : diagnostics) {
if (record.layer == layer && record.event == event &&
record.status == status) {
return;
}
}
throw std::runtime_error("missing diagnostic: " + layer + "/" + event +
"/" + status);
};

progress("starting backend");
rivet::linux_runtime::Backend backend(std::move(config));
backend.start();
Expand Down Expand Up @@ -311,6 +333,10 @@ int main(int argc, char** argv) {
}

progress("backend stopped");
require_diagnostic("abi-bridge", "backend-init", "success");
require_diagnostic("protocol", "handshake", "success");
require_diagnostic("native-client", "rpc-dispatch", "success");
require_diagnostic("native-runtime", "backend-stop", "success");
std::cout << "Rivet embedded Linux round-trip passed\n";
return 0;
} catch (std::exception const& error) {
Expand Down
93 changes: 92 additions & 1 deletion platform/linux/runtime/backend.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -148,6 +148,17 @@ std::exception_ptr stopped_error() {
return std::make_exception_ptr(std::runtime_error("Rivet backend stopped"));
}

std::string exception_message(std::exception_ptr error) noexcept {
if (!error) return "unknown failure";
try {
std::rethrow_exception(error);
} catch (std::exception const& exception) {
return exception.what();
} catch (...) {
return "non-standard exception";
}
}

ptr quoted_symbol(std::string const& name) {
auto const quote = Sstring_to_symbol("quote");
auto const module = Sstring_to_symbol(name.c_str());
Expand Down Expand Up @@ -179,11 +190,13 @@ class Backend::Impl {
throw std::logic_error("Rivet backend instances cannot be restarted");
}
started_ = true;
emit_diagnostic("native-runtime", "backend-start", "begin");

auto endpoints = create_socket_endpoints();
auto server_read = std::move(endpoints.server_read);
auto server_write = std::move(endpoints.server_write);
transport_ = std::make_unique<FdTransport>(std::move(endpoints.native));
emit_diagnostic("transport", "channel-opened", "success");

ready_ = std::make_shared<std::promise<void>>();
ready_future_ = ready_->get_future();
Expand All @@ -200,7 +213,17 @@ class Backend::Impl {

// The first valid frame from Racket is Hello. Waiting for it makes start
// fail synchronously when boot files, core.zo, or the entry point are bad.
ready_future_.get();
try {
ready_future_.get();
emit_diagnostic("protocol", "handshake", "success");
emit_diagnostic("native-runtime", "backend-start", "success");
} catch (...) {
emit_diagnostic("protocol", "handshake", "failure",
exception_message(std::current_exception()));
emit_diagnostic("native-runtime", "backend-start", "failure",
exception_message(std::current_exception()));
throw;
}
}

void stop() {
Expand All @@ -211,13 +234,16 @@ class Backend::Impl {
if (!started_) {
return;
}
stopping_.store(true, std::memory_order_release);
running_.store(false, std::memory_order_release);
}
emit_diagnostic("native-runtime", "backend-stop", "begin");

try {
std::lock_guard write_lock(write_mutex_);
auto* transport = transport_.get();
if (transport != nullptr) {
note_protocol_event("shutdown");
write_frame(*transport, Frame{MessageType::Shutdown, 0, {}});
}
} catch (...) {
Expand All @@ -238,6 +264,7 @@ class Backend::Impl {
}

reject_all(stopped_error());
emit_diagnostic("native-runtime", "backend-stop", "success");
}

bool running() const noexcept {
Expand Down Expand Up @@ -286,6 +313,9 @@ class Backend::Impl {

auto* transport = transport_.get();
if (transport != nullptr) {
note_protocol_event("cancel");
emit_diagnostic("native-client", "request-cancel", "begin", "",
request_id);
write_frame(*transport, Frame{MessageType::Cancel, request_id, {}});
}
}
Expand All @@ -296,6 +326,31 @@ class Backend::Impl {
}

private:
void note_protocol_event(std::string event) noexcept {
std::lock_guard lock(diagnostic_mutex_);
last_protocol_event_ = std::move(event);
}

void emit_diagnostic(std::string layer,
std::string event,
std::string status,
std::string message = {},
std::optional<std::uint64_t> request_id = std::nullopt)
noexcept {
DiagnosticRecord record;
{
std::lock_guard lock(diagnostic_mutex_);
record = DiagnosticRecord{std::move(layer), std::move(event),
std::move(status), last_protocol_event_,
request_id, std::move(message)};
}
try {
if (config_.diagnostic_sink) config_.diagnostic_sink(record);
} catch (...) {
// Diagnostics must never become a new runtime failure path.
}
}

std::uint64_t submit_request(std::string rpc_name,
Value::List arguments,
PendingRequest pending) {
Expand Down Expand Up @@ -323,6 +378,9 @@ class Backend::Impl {
}
}

note_protocol_event("request");
emit_diagnostic("native-client", "rpc-dispatch", "begin", rpc_name, id);

Value::List request;
request.reserve(arguments.size() + 1);
request.emplace_back(std::move(rpc_name));
Expand Down Expand Up @@ -355,13 +413,17 @@ class Backend::Impl {
write_frame(*transport, Frame{MessageType::Cancel, id, {}});
}
} catch (...) {
emit_diagnostic("transport", "request-write", "failure",
exception_message(std::current_exception()), id);
fail_request(id, std::current_exception());
}

return id;
}

void racket_main(UniqueFd server_read, UniqueFd server_write) noexcept {
emit_diagnostic("abi-bridge", "backend-init", "begin");
bool initialized = false;
try {
racket_boot_arguments_t boot{};
boot.boot1_path = config_.petite_boot.c_str();
Expand All @@ -386,13 +448,25 @@ class Backend::Impl {
Scons(Sfixnum(server_read.get()),
Scons(Sfixnum(server_write.get()), Snil));

initialized = true;
emit_diagnostic("abi-bridge", "backend-init", "success");

// The ports created by serve-fds own distinct descriptors referring to
// the same full-duplex socket. They close them during server teardown.
(void)server_read.release();
(void)server_write.release();
(void)racket_apply(procedure, args);
Sscheme_deinit();
emit_diagnostic(
"racket-backend", "backend-exit",
stopping_.load(std::memory_order_acquire) ? "success" : "failure",
stopping_.load(std::memory_order_acquire)
? ""
: "backend returned before native shutdown");
} catch (...) {
emit_diagnostic(initialized ? "racket-backend" : "abi-bridge",
initialized ? "backend-exit" : "backend-init", "failure",
exception_message(std::current_exception()));
// Owned descriptors are closed on native startup failures. Once they are
// transferred, serve-fds owns their lifetime.
}
Expand All @@ -414,28 +488,40 @@ class Backend::Impl {

auto frame = read_frame(*transport);
if (!frame.has_value()) {
if (!stopping_.load(std::memory_order_acquire)) {
emit_diagnostic("transport", "channel-closed", "failure",
"Rivet transport closed unexpectedly");
}
break;
}

switch (frame->type) {
case MessageType::Hello:
note_protocol_event("hello");
accept_hello(*frame);
break;
case MessageType::Response:
note_protocol_event("response");
emit_diagnostic("native-client", "rpc-dispatch", "success", "",
frame->id);
resolve_request(frame->id, decode_value(frame->payload));
break;
case MessageType::Error: {
note_protocol_event("error");
auto error_value = decode_value(frame->payload);
std::string message{"Rivet backend error"};
if (auto* text = std::get_if<std::string>(&error_value.data)) {
message = *text;
}
emit_diagnostic("racket-backend", "rpc-dispatch", "failure",
message, frame->id);
fail_request(
frame->id,
std::make_exception_ptr(std::runtime_error(std::move(message))));
break;
}
case MessageType::Event:
note_protocol_event("event");
deliver_event(decode_value(frame->payload));
break;
default:
Expand All @@ -447,6 +533,8 @@ class Backend::Impl {
set_ready_exception(stopped_error());
}
} catch (...) {
emit_diagnostic("protocol", "reader-loop", "failure",
exception_message(std::current_exception()));
set_ready_exception(std::current_exception());
reject_all(std::current_exception());
}
Expand Down Expand Up @@ -602,6 +690,7 @@ class Backend::Impl {
std::mutex write_mutex_;
std::mutex pending_mutex_;
std::mutex event_mutex_;
std::mutex diagnostic_mutex_;
std::unique_ptr<FdTransport> transport_;
std::thread racket_thread_;
std::thread reader_thread_;
Expand All @@ -610,6 +699,8 @@ class Backend::Impl {
detail::RequestIdAllocator request_ids_;
std::atomic<bool> running_{false};
std::atomic<bool> hello_seen_{false};
std::atomic<bool> stopping_{false};
std::string last_protocol_event_{"none"};
bool started_{false};
std::shared_ptr<std::promise<void>> ready_;
std::future<void> ready_future_;
Expand Down
2 changes: 2 additions & 0 deletions platform/linux/runtime/backend.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
#include <utility>
#include <vector>

#include "rivet/diagnostics.hpp"
#include "rivet/protocol.hpp"

namespace rivet::linux_runtime {
Expand All @@ -26,6 +27,7 @@ struct RacketRuntimeConfig {
std::string module_name{"backend"};
std::string entry_symbol{"start"};
std::size_t max_pending_requests{1024};
DiagnosticSink diagnostic_sink{default_diagnostic_sink()};
};

struct PendingCall {
Expand Down
Loading
Loading