ssb: Show muxrpc command names when possible in verbose logging.

This commit is contained in:
Cory McWilliams 2024-10-23 15:37:28 -04:00
parent 86751362cb
commit 2f193e64c8

View File

@ -698,7 +698,8 @@ static void _tf_ssb_request_activity_timer(uv_timer_t* timer)
} }
} }
static bool _tf_ssb_connection_get_request_callback(tf_ssb_connection_t* connection, int32_t request_number, tf_ssb_rpc_callback_t** out_callback, void** out_user_data) static bool _tf_ssb_connection_get_request_callback(
tf_ssb_connection_t* connection, int32_t request_number, tf_ssb_rpc_callback_t** out_callback, void** out_user_data, const char** out_name)
{ {
if (!connection->requests) if (!connection->requests)
{ {
@ -715,6 +716,10 @@ static bool _tf_ssb_connection_get_request_callback(tf_ssb_connection_t* connect
{ {
*out_user_data = request->user_data; *out_user_data = request->user_data;
} }
if (out_name)
{
*out_name = request->name;
}
request->last_active = uv_now(connection->ssb->loop); request->last_active = uv_now(connection->ssb->loop);
if (uv_timer_get_due_in(&connection->ssb->request_activity_timer) == 0) if (uv_timer_get_due_in(&connection->ssb->request_activity_timer) == 0)
{ {
@ -838,6 +843,7 @@ void tf_ssb_connection_remove_request(tf_ssb_connection_t* connection, int32_t r
bool tf_ssb_connection_rpc_send(tf_ssb_connection_t* connection, uint8_t flags, int32_t request_number, const char* new_request_name, const uint8_t* message, size_t size, bool tf_ssb_connection_rpc_send(tf_ssb_connection_t* connection, uint8_t flags, int32_t request_number, const char* new_request_name, const uint8_t* message, size_t size,
tf_ssb_rpc_callback_t* callback, tf_ssb_callback_cleanup_t* cleanup, void* user_data) tf_ssb_rpc_callback_t* callback, tf_ssb_callback_cleanup_t* cleanup, void* user_data)
{ {
const char* request_name = "<unknown>";
if (!connection) if (!connection)
{ {
if (cleanup) if (cleanup)
@ -849,10 +855,10 @@ bool tf_ssb_connection_rpc_send(tf_ssb_connection_t* connection, uint8_t flags,
if (flags & k_ssb_rpc_flag_new_request) if (flags & k_ssb_rpc_flag_new_request)
{ {
assert(request_number > 0); assert(request_number > 0);
assert(!_tf_ssb_connection_get_request_callback(connection, request_number, NULL, NULL)); assert(!_tf_ssb_connection_get_request_callback(connection, request_number, NULL, NULL, NULL));
assert(new_request_name); assert(new_request_name);
} }
else if (!_tf_ssb_connection_get_request_callback(connection, request_number, NULL, NULL)) else if (!_tf_ssb_connection_get_request_callback(connection, request_number, NULL, NULL, &request_name))
{ {
if (flags & k_ssb_rpc_flag_binary) if (flags & k_ssb_rpc_flag_binary)
{ {
@ -874,9 +880,9 @@ bool tf_ssb_connection_rpc_send(tf_ssb_connection_t* connection, uint8_t flags,
memcpy(combined + 1 + 2 * sizeof(uint32_t), message, size); memcpy(combined + 1 + 2 * sizeof(uint32_t), message, size);
if (connection->ssb->verbose) if (connection->ssb->verbose)
{ {
tf_printf(MAGENTA "%s RPC SEND" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B] %.*s\n", connection->name, (flags & k_ssb_rpc_flag_end_error) ? "true" : "false", tf_printf(MAGENTA "%s RPC SEND[%s]" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B] %.*s\n", connection->name, request_name,
(flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type], request_number, size, (flags & k_ssb_rpc_flag_end_error) ? "true" : "false", (flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type],
(flags & k_ssb_rpc_mask_type) == k_ssb_rpc_flag_binary ? 0 : (int)size, message); request_number, size, (flags & k_ssb_rpc_mask_type) == k_ssb_rpc_flag_binary ? 0 : (int)size, message);
} }
_tf_ssb_connection_add_debug_message(connection, true, flags & k_ssb_rpc_mask_send, request_number, message, size); _tf_ssb_connection_add_debug_message(connection, true, flags & k_ssb_rpc_mask_send, request_number, message, size);
_tf_ssb_connection_box_stream_send(connection, combined, 1 + 2 * sizeof(uint32_t) + size); _tf_ssb_connection_box_stream_send(connection, combined, 1 + 2 * sizeof(uint32_t) + size);
@ -1613,21 +1619,22 @@ static void _tf_ssb_connection_rpc_recv(tf_ssb_connection_t* connection, uint8_t
} }
else if (flags & k_ssb_rpc_flag_json) else if (flags & k_ssb_rpc_flag_json)
{ {
char id[k_id_base64_len] = ""; tf_ssb_rpc_callback_t* callback = NULL;
tf_ssb_id_bin_to_str(id, sizeof(id), connection->serverpub); void* user_data = NULL;
const char* request_name = "<unknown>";
bool have_request = _tf_ssb_connection_get_request_callback(connection, -request_number, &callback, &user_data, &request_name);
if (connection->ssb->verbose) if (connection->ssb->verbose)
{ {
tf_printf(CYAN "%s RPC RECV" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B] %.*s\n", connection->name, (flags & k_ssb_rpc_flag_end_error) ? "true" : "false", tf_printf(CYAN "%s RPC RECV[%s]" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B] %.*s\n", connection->name, request_name,
(flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type], request_number, size, (int)size, message); (flags & k_ssb_rpc_flag_end_error) ? "true" : "false", (flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type],
request_number, size, (int)size, message);
} }
JSContext* context = connection->ssb->context; JSContext* context = connection->ssb->context;
JSValue val = JS_ParseJSON(context, (const char*)message, size, NULL); JSValue val = JS_ParseJSON(context, (const char*)message, size, NULL);
if (!JS_IsUndefined(val)) if (!JS_IsUndefined(val))
{ {
tf_ssb_rpc_callback_t* callback = NULL; if (have_request)
void* user_data = NULL;
if (_tf_ssb_connection_get_request_callback(connection, -request_number, &callback, &user_data))
{ {
if (callback) if (callback)
{ {
@ -1680,14 +1687,17 @@ static void _tf_ssb_connection_rpc_recv(tf_ssb_connection_t* connection, uint8_t
} }
else if ((flags & k_ssb_rpc_mask_type) == k_ssb_rpc_flag_binary) else if ((flags & k_ssb_rpc_mask_type) == k_ssb_rpc_flag_binary)
{ {
if (connection->ssb->verbose)
{
tf_printf(CYAN "%s RPC RECV" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B]\n", connection->name, (flags & k_ssb_rpc_flag_end_error) ? "true" : "false",
(flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type], request_number, size);
}
tf_ssb_rpc_callback_t* callback = NULL; tf_ssb_rpc_callback_t* callback = NULL;
void* user_data = NULL; void* user_data = NULL;
if (_tf_ssb_connection_get_request_callback(connection, -request_number, &callback, &user_data)) const char* request_name = "<unknown>";
bool have_request = _tf_ssb_connection_get_request_callback(connection, -request_number, &callback, &user_data, &request_name);
if (connection->ssb->verbose)
{
tf_printf(CYAN "%s RPC RECV[%s]" RESET " end/error=%s stream=%s type=%s RN=%d: [%zd B]\n", connection->name, request_name,
(flags & k_ssb_rpc_flag_end_error) ? "true" : "false", (flags & k_ssb_rpc_flag_stream) ? "true" : "false", k_ssb_type_names[flags & k_ssb_rpc_mask_type],
request_number, size);
}
if (have_request)
{ {
if (callback) if (callback)
{ {