v0.7.5 - Complete debug logging cleanup - remove all remaining DEBUG messages from websockets.c, config.c, and dm_admin.c

This commit is contained in:
Your Name
2025-10-10 10:52:14 -04:00
parent c90676d2b2
commit 00d16f8615
4 changed files with 40 additions and 170 deletions

View File

@@ -1 +1 @@
2377328
2383244

View File

@@ -1791,9 +1791,7 @@ int process_configuration_event(const cJSON* event) {
log_error("Invalid configuration event");
return -1;
}
log_info("Processing configuration event...");
// Validate event structure
cJSON* kind_obj = cJSON_GetObjectItem(event, "kind");
cJSON* pubkey_obj = cJSON_GetObjectItem(event, "pubkey");
@@ -2262,22 +2260,10 @@ int process_admin_event_in_config(cJSON* event, char* error_message, size_t erro
}
int kind = (int)cJSON_GetNumberValue(kind_obj);
printf(" Event kind: %d\n", kind);
// Extract and log event details for debugging
// Get event pubkey for authorization logging
cJSON* pubkey_obj = cJSON_GetObjectItem(event, "pubkey");
cJSON* content_obj = cJSON_GetObjectItem(event, "content");
cJSON* tags_obj = cJSON_GetObjectItem(event, "tags");
const char* event_pubkey = pubkey_obj ? cJSON_GetStringValue(pubkey_obj) : "unknown";
const char* event_content = content_obj ? cJSON_GetStringValue(content_obj) : "unknown";
printf(" Pubkey: %.16s...\n", event_pubkey ? event_pubkey : "null");
printf(" Content length: %zu\n", event_content ? strlen(event_content) : 0);
printf(" Has tags: %s\n", tags_obj ? "yes" : "no");
if (tags_obj && cJSON_IsArray(tags_obj)) {
printf(" Tags count: %d\n", cJSON_GetArraySize(tags_obj));
}
const char* event_pubkey = pubkey_obj ? cJSON_GetStringValue(pubkey_obj) : NULL;
// DEFENSE-IN-DEPTH: Use comprehensive admin authorization validation
if (!is_authorized_admin_event(event)) {
@@ -2308,10 +2294,7 @@ int process_admin_event_in_config(cJSON* event, char* error_message, size_t erro
int process_admin_config_event(cJSON* event, char* error_message, size_t error_size) {
cJSON* kind_obj = cJSON_GetObjectItem(event, "kind");
int kind = kind_obj ? (int)cJSON_GetNumberValue(kind_obj) : 0;
log_info("Processing admin configuration event");
printf(" Kind: %d\n", kind);
// Parse tags to find query commands according to API specification
cJSON* tags_obj = cJSON_GetObjectItem(event, "tags");
if (tags_obj && cJSON_IsArray(tags_obj)) {
@@ -2407,8 +2390,6 @@ int process_admin_auth_event(cJSON* event, char* error_message, size_t error_siz
cJSON* kind_obj = cJSON_GetObjectItem(event, "kind");
int kind = kind_obj ? (int)cJSON_GetNumberValue(kind_obj) : 0;
printf(" Kind: %d\n", kind);
// Extract and log additional event details for debugging
cJSON* content_obj = cJSON_GetObjectItem(event, "content");
cJSON* tags_obj = cJSON_GetObjectItem(event, "tags");
@@ -3072,9 +3053,6 @@ int handle_auth_query_unified(cJSON* event, const char* query_type, char* error_
return -1;
}
log_info("Processing unified auth query");
printf(" Query type: %s\n", query_type);
const char* sql = NULL;
int use_pattern_param = 0;
char* pattern_value = NULL;
@@ -3193,9 +3171,6 @@ int handle_config_query_unified(cJSON* event, const char* query_type, char* erro
return -1;
}
log_info("Processing unified config query");
printf(" Query type: %s\n", query_type);
const char* sql = NULL;
int use_pattern_param = 0;
char* pattern_value = NULL;
@@ -3320,10 +3295,6 @@ int handle_config_set_unified(cJSON* event, const char* config_key, const char*
return -1;
}
log_info("Processing unified config set command");
printf(" Key: %s\n", config_key);
printf(" Value: %s\n", config_value);
// Validate the configuration field before updating
char validation_error[512];
if (validate_config_field(config_key, config_value, validation_error, sizeof(validation_error)) != 0) {
@@ -3406,9 +3377,6 @@ int handle_system_command_unified(cJSON* event, const char* command, char* error
return -1;
}
log_info("Processing unified system command");
printf(" Command: %s\n", command);
if (strcmp(command, "clear_all_auth_rules") == 0) {
// Count existing rules first
const char* count_sql = "SELECT COUNT(*) FROM auth_rules";
@@ -3772,9 +3740,6 @@ int handle_stats_query_unified(cJSON* event, char* error_message, size_t error_s
return -1;
}
log_info("Processing unified stats query");
printf(" Query type: stats_query\n");
// Build response with database statistics
cJSON* response = cJSON_CreateObject();
cJSON_AddStringToObject(response, "query_type", "stats_query");
@@ -4009,11 +3974,6 @@ int handle_config_update_unified(cJSON* event, char* error_message, size_t error
const char* category = category_obj && cJSON_IsString(category_obj) ?
cJSON_GetStringValue(category_obj) : "general";
log_info("Processing config object");
printf(" Key: %s\n", key);
printf(" Value: %s\n", value);
printf(" Data type: %s\n", data_type);
printf(" Category: %s\n", category);
// Validate the configuration field before updating
char validation_error[512];
@@ -4571,7 +4531,6 @@ int process_startup_config_event(const cJSON* event) {
return -1;
}
log_info("Processing startup configuration event through admin API...");
// Validate event structure first
cJSON* kind_obj = cJSON_GetObjectItem(event, "kind");

View File

@@ -1597,11 +1597,6 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
const char* admin_pubkey = get_admin_pubkey_cached();
int is_admin = admin_pubkey && strlen(admin_pubkey) > 0 && strcmp(sender_pubkey, admin_pubkey) == 0;
log_info("NIP-17: Processing admin command from DM content");
char log_msg[256];
snprintf(log_msg, sizeof(log_msg), "NIP-17: Received DM content: '%.50s'%s", dm_content, strlen(dm_content) > 50 ? "..." : "");
log_info(log_msg);
// Parse DM content as JSON array of commands
cJSON* command_array = cJSON_Parse(dm_content);
if (!command_array || !cJSON_IsArray(command_array)) {
@@ -1623,9 +1618,6 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
// Check for stats commands
if (strstr(content_lower, "stats") != NULL || strstr(content_lower, "statistics") != NULL) {
log_info("NIP-17: Recognized plain text 'stats' command from admin");
log_info("NIP-17: Action: Generate and send relay statistics");
char* stats_text = generate_stats_text();
if (!stats_text) {
return -1;
@@ -1639,15 +1631,11 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
log_error(error_msg);
return -1;
}
log_success("NIP-17: Stats command processed successfully, response sent");
return 0;
}
// Check for config commands
else if (strstr(content_lower, "config") != NULL || strstr(content_lower, "configuration") != NULL) {
log_info("NIP-17: Recognized plain text 'config' command from admin");
log_info("NIP-17: Action: Generate and send relay configuration");
char* config_text = generate_config_text();
if (!config_text) {
return -1;
@@ -1661,8 +1649,7 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
log_error(error_msg);
return -1;
}
log_success("NIP-17: Config command processed successfully, response sent");
return 0;
}
else {
@@ -1670,7 +1657,7 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
int confirmation_result = handle_config_confirmation(sender_pubkey, dm_content);
if (confirmation_result != 0) {
if (confirmation_result > 0) {
log_success("NIP-17: Configuration confirmation processed successfully");
// Configuration confirmation processed successfully
} else if (confirmation_result == -2) {
// No pending changes
char no_pending_msg[256];
@@ -1691,7 +1678,6 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
int config_result = process_config_change_request(sender_pubkey, dm_content);
if (config_result != 0) {
if (config_result > 0) {
log_success("NIP-17: Configuration change request processed successfully");
return 1; // Return positive value to indicate response was handled
} else {
log_error("NIP-17: Configuration change request failed");
@@ -1699,12 +1685,10 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
}
}
log_info("NIP-17: Plain text content from admin not recognized as command, treating as user DM");
return 0; // Admin sent unrecognized plain text, treat as user DM
}
} else {
// Not admin, treat as user DM
log_info("NIP-17: Content is not JSON array and sender is not admin, treating as user DM");
return 0;
}
}
@@ -1713,8 +1697,6 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
if (cJSON_GetArraySize(command_array) > 0) {
cJSON* first_item = cJSON_GetArrayItem(command_array, 0);
if (cJSON_IsString(first_item) && strcmp(cJSON_GetStringValue(first_item), "stats") == 0) {
log_info("NIP-17: Processing 'stats' command directly");
// Get sender pubkey for response
cJSON* sender_pubkey_obj = cJSON_GetObjectItem(dm_event, "pubkey");
if (!sender_pubkey_obj || !cJSON_IsString(sender_pubkey_obj)) {
@@ -1742,8 +1724,7 @@ int process_nip17_admin_command(cJSON* dm_event, char* error_message, size_t err
strncpy(error_message, error_msg, error_size - 1);
return -1;
}
log_success("NIP-17: Stats command processed successfully");
return 0;
}
}

View File

@@ -451,10 +451,6 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
strncpy(error_message, "error: validation failed", sizeof(error_message) - 1);
break;
}
char debug_error_msg[256];
snprintf(debug_error_msg, sizeof(debug_error_msg),
"DEBUG VALIDATION ERROR: %s", error_message);
log_warning(debug_error_msg);
}
// Cleanup event JSON string
@@ -511,55 +507,33 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
cJSON* kind_obj = cJSON_GetObjectItem(event, "kind");
if (kind_obj && cJSON_IsNumber(kind_obj)) {
int event_kind = (int)cJSON_GetNumberValue(kind_obj);
log_info("DEBUG ADMIN: Checking if admin event processing is needed");
// Log reception of Kind 23456 events
if (event_kind == 23456) {
char* event_json_debug = cJSON_Print(event);
char debug_received_msg[1024];
snprintf(debug_received_msg, sizeof(debug_received_msg),
"RECEIVED Kind %d event: %s", event_kind,
event_json_debug ? event_json_debug : "Failed to serialize");
log_info(debug_received_msg);
if (event_json_debug) {
free(event_json_debug);
}
log_info("Received admin event (kind 23456)");
}
if (event_kind == 23456) {
// Enhanced admin event security - check authorization first
log_info("DEBUG ADMIN: Admin event detected, checking authorization");
char auth_error[512] = {0};
int auth_result = is_authorized_admin_event(event, auth_error, sizeof(auth_error));
if (auth_result != 0) {
// Authorization failed - log and reject
log_warning("DEBUG ADMIN: Admin event authorization failed");
log_warning("Admin event authorization failed");
result = -1;
size_t error_len = strlen(auth_error);
size_t copy_len = (error_len < sizeof(error_message) - 1) ? error_len : sizeof(error_message) - 1;
memcpy(error_message, auth_error, copy_len);
error_message[copy_len] = '\0';
char debug_auth_error_msg[600];
snprintf(debug_auth_error_msg, sizeof(debug_auth_error_msg),
"DEBUG ADMIN AUTH ERROR: %.400s", auth_error);
log_warning(debug_auth_error_msg);
} else {
// Authorization successful - process through admin API
log_info("DEBUG ADMIN: Admin event authorized, processing through admin API");
log_info("Processing authorized admin event");
char admin_error[512] = {0};
int admin_result = process_admin_event_in_config(event, admin_error, sizeof(admin_error), wsi);
char debug_admin_msg[256];
snprintf(debug_admin_msg, sizeof(debug_admin_msg),
"DEBUG ADMIN: process_admin_event_in_config returned %d", admin_result);
log_info(debug_admin_msg);
// Log results for Kind 23456 events
if (event_kind == 23456) {
if (admin_result == 0) {
@@ -576,25 +550,20 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
}
if (admin_result != 0) {
log_error("DEBUG ADMIN: Failed to process admin event through admin API");
log_error("Failed to process admin event");
result = -1;
size_t error_len = strlen(admin_error);
size_t copy_len = (error_len < sizeof(error_message) - 1) ? error_len : sizeof(error_message) - 1;
memcpy(error_message, admin_error, copy_len);
error_message[copy_len] = '\0';
char debug_admin_error_msg[600];
snprintf(debug_admin_error_msg, sizeof(debug_admin_error_msg),
"DEBUG ADMIN ERROR: %.400s", admin_error);
log_error(debug_admin_error_msg);
} else {
log_success("DEBUG ADMIN: Admin event processed successfully through admin API");
log_success("Admin event processed successfully");
// Admin events are processed by the admin API, not broadcast to subscriptions
}
}
} else if (event_kind == 1059) {
// Check for NIP-17 gift wrap admin messages
log_info("DEBUG NIP17: Detected kind 1059 gift wrap event");
log_info("Processing NIP-17 gift wrap event");
char nip17_error[512] = {0};
cJSON* response_event = process_nip17_admin_message(event, nip17_error, sizeof(nip17_error), wsi);
@@ -603,53 +572,38 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Check if this is an error or if the command was already handled
if (strlen(nip17_error) > 0) {
// There was an actual error
log_error("DEBUG NIP17: NIP-17 admin message processing failed");
log_error("NIP-17 admin message processing failed");
result = -1;
size_t error_len = strlen(nip17_error);
size_t copy_len = (error_len < sizeof(error_message) - 1) ? error_len : sizeof(error_message) - 1;
memcpy(error_message, nip17_error, copy_len);
error_message[copy_len] = '\0';
char debug_nip17_error_msg[600];
snprintf(debug_nip17_error_msg, sizeof(debug_nip17_error_msg),
"DEBUG NIP17 ERROR: %.400s", nip17_error);
log_error(debug_nip17_error_msg);
} else {
// No error message means the command was already handled (plain text commands)
log_success("DEBUG NIP17: NIP-17 admin message processed successfully (already handled)");
log_success("NIP-17 admin message processed successfully");
// Store the original gift wrap event in database
if (store_event(event) != 0) {
log_error("DEBUG NIP17: Failed to store gift wrap event in database");
log_error("Failed to store gift wrap event in database");
result = -1;
strncpy(error_message, "error: failed to store gift wrap event", sizeof(error_message) - 1);
} else {
log_info("DEBUG NIP17: Gift wrap event stored successfully in database");
log_info("Gift wrap event stored successfully in database");
}
}
} else {
log_success("DEBUG NIP17: NIP-17 admin message processed successfully");
log_success("NIP-17 admin message processed successfully");
// Store the original gift wrap event in database (unlike kind 23456)
if (store_event(event) != 0) {
log_error("DEBUG NIP17: Failed to store gift wrap event in database");
log_error("Failed to store gift wrap event in database");
result = -1;
strncpy(error_message, "error: failed to store gift wrap event", sizeof(error_message) - 1);
cJSON_Delete(response_event);
} else {
log_info("DEBUG NIP17: Gift wrap event stored successfully in database");
// Debug: Print response event before broadcasting
char* debug_before_broadcast = cJSON_Print(response_event);
if (debug_before_broadcast) {
log_info("DEBUG EVENT: Before broadcasting response event");
printf(" Response Event: %s\n", debug_before_broadcast);
free(debug_before_broadcast);
}
log_info("Gift wrap event stored successfully in database");
// Broadcast RESPONSE event to matching persistent subscriptions
int broadcast_count = broadcast_event_to_subscriptions(response_event);
char debug_broadcast_msg[128];
snprintf(debug_broadcast_msg, sizeof(debug_broadcast_msg),
"DEBUG NIP17 BROADCAST: Response event broadcast to %d subscriptions", broadcast_count);
log_info(debug_broadcast_msg);
broadcast_event_to_subscriptions(response_event);
// Clean up response event
cJSON_Delete(response_event);
@@ -657,66 +611,54 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
}
} else if (event_kind == 14) {
// Check for DM stats commands addressed to relay
log_info("DEBUG DM: Detected kind 14 DM event");
log_info("Processing DM event");
char dm_error[512] = {0};
int dm_result = process_dm_stats_command(event, dm_error, sizeof(dm_error), wsi);
if (dm_result != 0) {
log_error("DEBUG DM: DM stats command processing failed");
log_error("DM stats command processing failed");
result = -1;
size_t error_len = strlen(dm_error);
size_t copy_len = (error_len < sizeof(error_message) - 1) ? error_len : sizeof(error_message) - 1;
memcpy(error_message, dm_error, copy_len);
error_message[copy_len] = '\0';
char debug_dm_error_msg[600];
snprintf(debug_dm_error_msg, sizeof(debug_dm_error_msg),
"DEBUG DM ERROR: %.400s", dm_error);
log_error(debug_dm_error_msg);
} else {
log_success("DEBUG DM: DM stats command processed successfully");
log_success("DM stats command processed successfully");
// Store the DM event in database
if (store_event(event) != 0) {
log_error("DEBUG DM: Failed to store DM event in database");
log_error("Failed to store DM event in database");
result = -1;
strncpy(error_message, "error: failed to store DM event", sizeof(error_message) - 1);
} else {
log_info("DEBUG DM: DM event stored successfully in database");
log_info("DM event stored successfully in database");
// Broadcast DM event to matching persistent subscriptions
int broadcast_count = broadcast_event_to_subscriptions(event);
char debug_broadcast_msg[128];
snprintf(debug_broadcast_msg, sizeof(debug_broadcast_msg),
"DEBUG DM BROADCAST: DM event broadcast to %d subscriptions", broadcast_count);
log_info(debug_broadcast_msg);
broadcast_event_to_subscriptions(event);
}
}
} else {
// Regular event - store in database and broadcast
log_info("DEBUG STORAGE: Regular event - storing in database");
log_info("Storing regular event in database");
if (store_event(event) != 0) {
log_error("DEBUG STORAGE: Failed to store event in database");
log_error("Failed to store event in database");
result = -1;
strncpy(error_message, "error: failed to store event", sizeof(error_message) - 1);
} else {
log_info("DEBUG STORAGE: Event stored successfully in database");
log_info("Event stored successfully in database");
// Broadcast event to matching persistent subscriptions
int broadcast_count = broadcast_event_to_subscriptions(event);
char debug_broadcast_msg[128];
snprintf(debug_broadcast_msg, sizeof(debug_broadcast_msg),
"DEBUG BROADCAST: Event broadcast to %d subscriptions", broadcast_count);
log_info(debug_broadcast_msg);
broadcast_event_to_subscriptions(event);
}
}
} else {
// Event without valid kind - try normal storage
log_warning("DEBUG STORAGE: Event without valid kind - trying normal storage");
log_warning("Event without valid kind - trying normal storage");
if (store_event(event) != 0) {
log_error("DEBUG STORAGE: Failed to store event without kind in database");
log_error("Failed to store event without kind in database");
result = -1;
strncpy(error_message, "error: failed to store event", sizeof(error_message) - 1);
} else {
log_info("DEBUG STORAGE: Event without kind stored successfully in database");
log_info("Event without kind stored successfully in database");
broadcast_event_to_subscriptions(event);
}
}
@@ -731,25 +673,13 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
cJSON_AddItemToArray(response, cJSON_CreateBool(result == 0));
cJSON_AddItemToArray(response, cJSON_CreateString(strlen(error_message) > 0 ? error_message : ""));
// TODO: REPLACE - Remove wasteful cJSON_Print conversion
char *response_str = cJSON_Print(response);
if (response_str) {
char debug_response_msg[512];
snprintf(debug_response_msg, sizeof(debug_response_msg),
"DEBUG RESPONSE: Sending OK response: %s", response_str);
log_info(debug_response_msg);
size_t response_len = strlen(response_str);
unsigned char *buf = malloc(LWS_PRE + response_len);
if (buf) {
memcpy(buf + LWS_PRE, response_str, response_len);
int write_result = lws_write(wsi, buf + LWS_PRE, response_len, LWS_WRITE_TEXT);
char debug_write_msg[128];
snprintf(debug_write_msg, sizeof(debug_write_msg),
"DEBUG RESPONSE: lws_write returned %d", write_result);
log_info(debug_write_msg);
lws_write(wsi, buf + LWS_PRE, response_len, LWS_WRITE_TEXT);
free(buf);
}
free(response_str);