From ab75ec07f8e89a62a15e9036eede7807510792ce Mon Sep 17 00:00:00 2001 From: Cory McWilliams Date: Sun, 22 Jan 2023 20:37:19 +0000 Subject: [PATCH] Added some storage+debugging to track what happens before we disconnect. Maybe I'll learn something. git-svn-id: https://www.unprompted.com/svn/projects/tildefriends/trunk@4146 ed5197a5-7fde-0310-b194-c3ffbd925b24 --- core/core.js | 4 ++ src/ssb.c | 122 +++++++++++++++++++++++++++++++++++++++++++++++++++ src/ssb.h | 2 + src/task.c | 7 +++ 4 files changed, 135 insertions(+) diff --git a/core/core.js b/core/core.js index 47184078..8cd9dbee 100644 --- a/core/core.js +++ b/core/core.js @@ -843,6 +843,10 @@ loadSettings().then(function() { var data = trace(); response.writeHead(200, {"Content-Type": "application/json; charset=utf-8", "Content-Length": data.length.toString()}); return response.end(data); + } else if (match = /^\/disconnections$/.exec(request.uri)) { + var data = utf8Encode(JSON.stringify(disconnectionsDebug(), null, 2)); + response.writeHead(200, {"Content-Type": "application/json; charset=utf-8", "Content-Length": data.byteLength.toString()}); + return response.end(data); } else if (match = /^\/debug$/.exec(request.uri)) { var data = JSON.stringify(getDebug(), null, 2); response.writeHead(200, {"Content-Type": "application/json; charset=utf-8", "Content-Length": data.length.toString()}); diff --git a/src/ssb.c b/src/ssb.c index e6bb3ff8..0db1ecbf 100644 --- a/src/ssb.c +++ b/src/ssb.c @@ -71,12 +71,31 @@ typedef enum { enum { k_connections_changed_callbacks_max = 8, k_tf_ssb_rpc_message_body_length_max = 1 * 1024 * 1024, + k_debug_close_message_count = 32, + k_debug_close_connection_count = 8, }; typedef struct _tf_ssb_broadcast_t tf_ssb_broadcast_t; typedef struct _tf_ssb_connection_t tf_ssb_connection_t; typedef struct _tf_ssb_request_t tf_ssb_request_t; +typedef struct _tf_ssb_debug_message_t +{ + bool outgoing; + int flags; + int32_t request_number; + size_t size; + uint8_t data[]; +} tf_ssb_debug_message_t; + +typedef struct _tf_ssb_debug_close_t +{ + char id[k_id_base64_len]; + char tunnel[k_id_base64_len]; + char reason[128]; + tf_ssb_debug_message_t* messages[k_debug_close_message_count]; +} tf_ssb_debug_close_t; + typedef struct _tf_ssb_request_t { int32_t request_number; @@ -196,6 +215,8 @@ typedef struct _tf_ssb_t tf_ssb_broadcasts_changed_callback_node_t* broadcasts_changed; int broadcasts_changed_count; + + tf_ssb_debug_close_t debug_close[k_debug_close_connection_count]; } tf_ssb_t; typedef struct _tf_ssb_connection_message_request_t @@ -276,6 +297,8 @@ typedef struct _tf_ssb_connection_t tf_ssb_connection_scheduled_t* scheduled; int scheduled_count; + + tf_ssb_debug_message_t* debug_messages[k_debug_close_message_count]; } tf_ssb_connection_t; static JSClassID _connection_class_id; @@ -290,6 +313,53 @@ static void _tf_ssb_nonce_inc(uint8_t* nonce); static void _tf_ssb_write(tf_ssb_connection_t* connection, void* data, size_t size); static void _tf_ssb_connection_finalizer(JSRuntime* runtime, JSValue value); +static void _tf_ssb_add_debug_close(tf_ssb_t* ssb, tf_ssb_connection_t* connection, const char* reason) +{ + for (int i = 0; i < k_debug_close_message_count; i++) + { + tf_free(ssb->debug_close[k_debug_close_connection_count - 1].messages[i]); + } + for (int i = k_debug_close_connection_count - 1; i > 0; i--) + { + ssb->debug_close[i] = ssb->debug_close[i - 1]; + } + + tf_ssb_id_bin_to_str(ssb->debug_close[0].id, sizeof(ssb->debug_close[0].id), connection->serverpub); + if (connection->tunnel_connection) + { + tf_ssb_id_bin_to_str(ssb->debug_close[0].tunnel, sizeof(ssb->debug_close[0].tunnel), connection->tunnel_connection->serverpub); + } + else + { + memset(ssb->debug_close[0].tunnel, 0, sizeof(ssb->debug_close[0].tunnel)); + } + memcpy(ssb->debug_close[0].messages, connection->debug_messages, sizeof(connection->debug_messages)); + memset(connection->debug_messages, 0, sizeof(connection->debug_messages)); + snprintf(ssb->debug_close[0].reason, sizeof(ssb->debug_close[0].reason), "%s", reason); +} + +static void _tf_ssb_connection_add_debug_message(tf_ssb_connection_t* connection, bool outgoing, int flags, int32_t request_number, const uint8_t* data, size_t size) +{ + if (connection->debug_messages[k_debug_close_message_count - 1]) + { + tf_free(connection->debug_messages[k_debug_close_message_count - 1]); + } + for (int i = k_debug_close_message_count - 1; i > 0; i--) + { + connection->debug_messages[i] = connection->debug_messages[i - 1]; + } + tf_ssb_debug_message_t* message = tf_malloc(sizeof(tf_ssb_debug_message_t) + size); + *message = (tf_ssb_debug_message_t) + { + .outgoing = outgoing, + .flags = flags, + .request_number = request_number, + .size = size, + }; + memcpy(message + 1, data, size); + connection->debug_messages[0] = message; +} + static void _tf_ssb_connection_send_close(tf_ssb_connection_t* connection) { uint8_t message_enc[34]; @@ -316,6 +386,7 @@ static void _tf_ssb_connection_close(tf_ssb_connection_t* connection, const char connection->state == k_tf_ssb_state_server_verified) { printf("Connection %s %p is closing: %s.\n", connection->name, connection, reason); + _tf_ssb_add_debug_close(connection->ssb, connection, reason); connection->state = k_tf_ssb_state_closing; _tf_ssb_connection_send_close(connection); } @@ -627,6 +698,7 @@ void tf_ssb_connection_rpc_send(tf_ssb_connection_t* connection, uint8_t flags, { printf(MAGENTA "%s RPC SEND" RESET " flags=%x RN=%d: [%zd B] %.*s\n", connection->name, flags, 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, request_number, message, size); _tf_ssb_connection_box_stream_send(connection, combined, 1 + 2 * sizeof(uint32_t) + size); tf_free(combined); connection->ssb->rpc_out++; @@ -1376,6 +1448,7 @@ static bool _tf_ssb_name_equals(JSContext* context, JSValue object, const char** static void _tf_ssb_connection_rpc_recv(tf_ssb_connection_t* connection, uint8_t flags, int32_t request_number, const uint8_t* message, size_t size) { connection->ssb->rpc_in++; + _tf_ssb_connection_add_debug_message(connection, false, flags, request_number, message, size); if (size == 0) { _tf_ssb_connection_close(connection, "rpc recv zero"); @@ -1740,6 +1813,12 @@ void _tf_ssb_connection_destroy(tf_ssb_connection_t* connection, const char* rea connection->message_requests = NULL; connection->message_requests_count = 0; + for (int i = 0; i < k_debug_close_message_count; i++) + { + tf_free(connection->debug_messages[i]); + connection->debug_messages[i] = NULL; + } + tf_free(connection); } } @@ -2206,6 +2285,13 @@ void tf_ssb_destroy(tf_ssb_t* ssb) ssb->broadcasts_count--; tf_free(broadcast); } + for (int i = 0; i < k_debug_close_connection_count; i++) + { + for (int j = 0; j < k_debug_close_message_count; j++) + { + tf_free(ssb->debug_close[i].messages[j]); + } + } tf_free(ssb); } @@ -3267,3 +3353,39 @@ void tf_ssb_connection_set_ebt_send_clock(tf_ssb_connection_t* connection, JSVal JS_FreeValue(context, connection->ebt_send_clock); connection->ebt_send_clock = JS_DupValue(context, send_clock); } + +JSValue tf_ssb_get_disconnection_debug(tf_ssb_t* ssb, JSContext* context) +{ + JSValue result = JS_NewObject(context); + JSValue disconnections = JS_NewArray(context); + for (int i = 0; i < k_debug_close_connection_count; i++) + { + JSValue disconnection = JS_NewObject(context); + if (*ssb->debug_close[i].id) + { + JS_SetPropertyStr(context, disconnection, "id", JS_NewString(context, ssb->debug_close[i].id)); + if (*ssb->debug_close[i].tunnel) + { + JS_SetPropertyStr(context, disconnection, "tunnel", JS_NewString(context, ssb->debug_close[i].tunnel)); + } + JS_SetPropertyStr(context, disconnection, "reason", JS_NewString(context, ssb->debug_close[i].reason)); + JSValue messages = JS_NewArray(context); + for (int j = 0; j < k_debug_close_message_count; j++) + { + if (ssb->debug_close[i].messages[j]) + { + JSValue message = JS_NewObject(context); + JS_SetPropertyStr(context, message, "direction", JS_NewString(context, ssb->debug_close[i].messages[j]->outgoing ? "out" : "in")); + JS_SetPropertyStr(context, message, "flags", JS_NewInt32(context, ssb->debug_close[i].messages[j]->flags)); + JS_SetPropertyStr(context, message, "request_number", JS_NewInt32(context, ssb->debug_close[i].messages[j]->request_number)); + JS_SetPropertyStr(context, message, "payload", JS_NewStringLen(context, (const char*)ssb->debug_close[i].messages[j]->data, ssb->debug_close[i].messages[j]->size)); + JS_SetPropertyUint32(context, messages, j, message); + } + } + JS_SetPropertyStr(context, disconnection, "messages", messages); + } + JS_SetPropertyUint32(context, disconnections, i, disconnection); + } + JS_SetPropertyStr(context, result, "disconnections", disconnections); + return result; +} diff --git a/src/ssb.h b/src/ssb.h index 167a9bd6..a7995ac3 100644 --- a/src/ssb.h +++ b/src/ssb.h @@ -182,3 +182,5 @@ JSClassID tf_ssb_get_connection_class_id(); void tf_ssb_get_stats(tf_ssb_t* ssb, tf_ssb_stats_t* out_stats); tf_ssb_blob_wants_t* tf_ssb_connection_get_blob_wants_state(tf_ssb_connection_t* connection); + +JSValue tf_ssb_get_disconnection_debug(tf_ssb_t* ssb, JSContext* context); diff --git a/src/task.c b/src/task.c index 087a14ec..09eda42c 100644 --- a/src/task.c +++ b/src/task.c @@ -826,6 +826,12 @@ static JSValue _tf_task_getDebug(JSContext* context, JSValueConst this_val, int return result; } +static JSValue _tf_task_disconnectionsDebug(JSContext* context, JSValueConst this_val, int argc, JSValueConst* argv) +{ + tf_task_t* task = JS_GetContextOpaque(context); + return tf_ssb_get_disconnection_debug(task->_ssb, context); +} + static JSValue _tf_task_getFile(JSContext* context, JSValueConst this_val, int argc, JSValueConst* argv) { tf_task_t* task = JS_GetContextOpaque(context); @@ -1572,6 +1578,7 @@ void tf_task_activate(tf_task_t* task) JS_SetPropertyStr(context, global, "trace", JS_NewCFunction(context, _tf_task_trace, "trace", 1)); JS_SetPropertyStr(context, global, "getStats", JS_NewCFunction(context, _tf_task_getStats, "getStats", 0)); JS_SetPropertyStr(context, global, "getDebug", JS_NewCFunction(context, _tf_task_getDebug, "getDebug", 0)); + JS_SetPropertyStr(context, global, "disconnectionsDebug", JS_NewCFunction(context, _tf_task_disconnectionsDebug, "disconnectionsDebug", 0)); } else {