laantungir/c-relay
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases 7 Wiki Activity

v0.7.12 - Implemented comprehensive debug system with 6 levels (0-5), file:line tracking at TRACE level, deployment script integration, and default level 5 for development

Browse Source
This commit is contained in:
Your Name
2025-10-13 12:44:18 -04:00
parent 49ffc3d99e
commit e3938a2c85
23 changed files with 2163 additions and 622 deletions
Download Patch File Download Diff File Expand all files Collapse all files

151
src/websockets.c
View File

@@ -3,6 +3,7 @@
// Includes
#include <stdio.h>
#include "debug.h"
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
@@ -31,10 +32,6 @@
#include "dm_admin.h" // DM admin functions including NIP-17
// Forward declarations for logging functions
void log_info(const char* message);
void log_success(const char* message);
void log_error(const char* message);
void log_warning(const char* message);
// Forward declarations for configuration functions
const char* get_config_value(const char* key);
@@ -201,7 +198,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Allocate buffer for JSON body transmission (no LWS_PRE needed for body)
unsigned char *json_buf = malloc(session_data->json_length);
if (!json_buf) {
log_error("Failed to allocate buffer for NIP-11 body transmission");
DEBUG_ERROR("Failed to allocate buffer for NIP-11 body transmission");
// Clean up session data
free(session_data->json_buffer);
free(session_data);
@@ -219,7 +216,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
free(json_buf);
if (write_result < 0) {
log_error("Failed to write NIP-11 JSON body");
DEBUG_ERROR("Failed to write NIP-11 JSON body");
// Clean up session data
free(session_data->json_buffer);
free(session_data);
@@ -244,20 +241,23 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
break;
case LWS_CALLBACK_ESTABLISHED:
DEBUG_TRACE("WebSocket connection established");
memset(pss, 0, sizeof(*pss));
pthread_mutex_init(&pss->session_lock, NULL);
// Get real client IP address
char client_ip[CLIENT_IP_MAX_LENGTH];
lws_get_peer_simple(wsi, client_ip, sizeof(client_ip));
// Ensure client_ip is null-terminated and copy safely
client_ip[CLIENT_IP_MAX_LENGTH - 1] = '\0';
size_t ip_len = strlen(client_ip);
size_t copy_len = (ip_len < CLIENT_IP_MAX_LENGTH - 1) ? ip_len : CLIENT_IP_MAX_LENGTH - 1;
memcpy(pss->client_ip, client_ip, copy_len);
pss->client_ip[copy_len] = '\0';
DEBUG_LOG("WebSocket connection established from %s", pss->client_ip);
// Initialize NIP-42 authentication state
pss->authenticated = 0;
pss->nip42_auth_required_events = get_config_bool("nip42_auth_required_events", 0);
@@ -267,6 +267,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
memset(pss->active_challenge, 0, sizeof(pss->active_challenge));
pss->challenge_created = 0;
pss->challenge_expires = 0;
DEBUG_TRACE("WebSocket connection initialization complete");
break;
case LWS_CALLBACK_RECEIVE:
@@ -336,7 +337,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
if (admin_pubkey && strcmp(event_pubkey, admin_pubkey) == 0) {
bypass_auth = 1;
} else {
log_info("DEBUG: Kind 23456 event but pubkey mismatch or no admin pubkey");
DEBUG_INFO("DEBUG: Kind 23456 event but pubkey mismatch or no admin pubkey");
}
}
@@ -353,7 +354,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
"NIP-42 authentication required for event kind %d", event_kind);
}
send_notice_message(wsi, auth_msg);
log_warning("Event rejected: NIP-42 authentication required for kind");
DEBUG_WARN("Event rejected: NIP-42 authentication required for kind");
}
cJSON_Delete(json);
free(message);
@@ -368,7 +369,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Extract event JSON string for unified validator
char *event_json_str = cJSON_Print(event);
if (!event_json_str) {
log_error("Failed to serialize event JSON for validation");
DEBUG_ERROR("Failed to serialize event JSON for validation");
cJSON* error_response = cJSON_CreateArray();
cJSON_AddItemToArray(error_response, cJSON_CreateString("OK"));
cJSON_AddItemToArray(error_response, cJSON_CreateString("unknown"));
@@ -460,7 +461,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
result = -1;
strncpy(error_message, "blocked: protected events not supported", sizeof(error_message) - 1);
error_message[sizeof(error_message) - 1] = '\0';
log_warning("Protected event rejected: protected events not enabled");
DEBUG_WARN("Protected event rejected: protected events not enabled");
} else {
// Protected events enabled - check authentication
cJSON* pubkey_obj = cJSON_GetObjectItem(event, "pubkey");
@@ -472,7 +473,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
result = -1;
strncpy(error_message, "auth-required: protected event requires authentication", sizeof(error_message) - 1);
error_message[sizeof(error_message) - 1] = '\0';
log_warning("Protected event rejected: authentication required");
DEBUG_WARN("Protected event rejected: authentication required");
}
}
}
@@ -484,10 +485,13 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
if (kind_obj && cJSON_IsNumber(kind_obj)) {
int event_kind = (int)cJSON_GetNumberValue(kind_obj);
DEBUG_TRACE("Processing event kind %d", event_kind);
// Log reception of Kind 23456 events
if (event_kind == 23456) {
DEBUG_LOG("Admin event (kind 23456) received");
}
if (event_kind == 23456) {
// Enhanced admin event security - check authorization first
@@ -496,7 +500,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
if (auth_result != 0) {
// Authorization failed - log and reject
log_warning("Admin event authorization failed");
DEBUG_WARN("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;
@@ -514,12 +518,12 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
char error_result_msg[512];
snprintf(error_result_msg, sizeof(error_result_msg),
"ERROR: Kind %d event processing failed: %s", event_kind, admin_error);
log_error(error_result_msg);
DEBUG_ERROR(error_result_msg);
}
}
if (admin_result != 0) {
log_error("Failed to process admin event");
DEBUG_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;
@@ -539,7 +543,7 @@ 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("NIP-17 admin message processing failed");
DEBUG_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;
@@ -550,7 +554,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// No error message means the command was already handled (plain text commands)
// Store the original gift wrap event in database
if (store_event(event) != 0) {
log_error("Failed to store gift wrap event in database");
DEBUG_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);
}
@@ -558,7 +562,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
} else {
// Store the original gift wrap event in database (unlike kind 23456)
if (store_event(event) != 0) {
log_error("Failed to store gift wrap event in database");
DEBUG_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);
@@ -577,7 +581,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
int dm_result = process_dm_stats_command(event, dm_error, sizeof(dm_error), wsi);
if (dm_result != 0) {
log_error("DM stats command processing failed");
DEBUG_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;
@@ -587,7 +591,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
} else {
// Store the DM event in database
if (store_event(event) != 0) {
log_error("Failed to store DM event in database");
DEBUG_ERROR("Failed to store DM event in database");
result = -1;
strncpy(error_message, "error: failed to store DM event", sizeof(error_message) - 1);
} else {
@@ -596,21 +600,23 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
}
}
} else {
DEBUG_TRACE("Storing regular event in database");
// Regular event - store in database and broadcast
if (store_event(event) != 0) {
log_error("Failed to store event in database");
DEBUG_ERROR("Failed to store event in database");
result = -1;
strncpy(error_message, "error: failed to store event", sizeof(error_message) - 1);
} else {
DEBUG_LOG("Event stored and broadcast (kind %d)", event_kind);
// Broadcast event to matching persistent subscriptions
broadcast_event_to_subscriptions(event);
}
}
} else {
// Event without valid kind - try normal storage
log_warning("Event without valid kind - trying normal storage");
DEBUG_WARN("Event without valid kind - trying normal storage");
if (store_event(event) != 0) {
log_error("Failed to store event without kind in database");
DEBUG_ERROR("Failed to store event without kind in database");
result = -1;
strncpy(error_message, "error: failed to store event", sizeof(error_message) - 1);
} else {
@@ -651,7 +657,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
send_nip42_auth_challenge(wsi, pss);
} else {
send_notice_message(wsi, "NIP-42 authentication required for subscriptions");
log_warning("REQ rejected: NIP-42 authentication required");
DEBUG_WARN("REQ rejected: NIP-42 authentication required");
}
cJSON_Delete(json);
free(message);
@@ -659,26 +665,28 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
}
// Handle REQ message
cJSON* sub_id = cJSON_GetArrayItem(json, 1);
cJSON* sub_id = cJSON_GetArrayItem(json, 1);
if (sub_id && cJSON_IsString(sub_id)) {
const char* subscription_id = cJSON_GetStringValue(sub_id);
if (sub_id && cJSON_IsString(sub_id)) {
const char* subscription_id = cJSON_GetStringValue(sub_id);
// Validate subscription ID before processing
if (!subscription_id) {
send_notice_message(wsi, "error: invalid subscription ID");
log_warning("REQ rejected: NULL subscription ID");
record_malformed_request(pss);
cJSON_Delete(json);
free(message);
return 0;
}
DEBUG_TRACE("Processing REQ message for subscription %s", subscription_id);
// Validate subscription ID before processing
if (!subscription_id) {
send_notice_message(wsi, "error: invalid subscription ID");
DEBUG_WARN("REQ rejected: NULL subscription ID");
record_malformed_request(pss);
cJSON_Delete(json);
free(message);
return 0;
}
// Check subscription ID format and length
size_t id_len = strlen(subscription_id);
if (id_len == 0 || id_len >= SUBSCRIPTION_ID_MAX_LENGTH) {
send_notice_message(wsi, "error: subscription ID too long or empty");
log_warning("REQ rejected: invalid subscription ID length");
DEBUG_WARN("REQ rejected: invalid subscription ID length");
cJSON_Delete(json);
free(message);
return 0;
@@ -704,7 +712,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
snprintf(debug_msg, sizeof(debug_msg),
"REQ rejected: invalid character '%c' (0x%02X) at position %zu in subscription ID: '%s'",
invalid_char, (unsigned char)invalid_char, invalid_pos, subscription_id);
log_warning(debug_msg);
DEBUG_WARN(debug_msg);
send_notice_message(wsi, "error: invalid characters in subscription ID");
cJSON_Delete(json);
free(message);
@@ -715,7 +723,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
cJSON* filters = cJSON_CreateArray();
if (!filters) {
send_notice_message(wsi, "error: failed to process filters");
log_error("REQ failed: could not create filters array");
DEBUG_ERROR("REQ failed: could not create filters array");
cJSON_Delete(json);
free(message);
return 0;
@@ -733,7 +741,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
char filter_error[512] = {0};
if (!validate_filter_array(filters, filter_error, sizeof(filter_error))) {
send_notice_message(wsi, filter_error);
log_warning("REQ rejected: invalid filters");
DEBUG_WARN("REQ rejected: invalid filters");
record_malformed_request(pss);
cJSON_Delete(filters);
cJSON_Delete(json);
@@ -746,6 +754,8 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Clean up the filters array we created
cJSON_Delete(filters);
DEBUG_LOG("REQ subscription %s processed, sending EOSE", subscription_id);
// Send EOSE (End of Stored Events)
cJSON* eose_response = cJSON_CreateArray();
if (eose_response) {
@@ -767,7 +777,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
}
} else {
send_notice_message(wsi, "error: missing or invalid subscription ID in REQ");
log_warning("REQ rejected: missing or invalid subscription ID");
DEBUG_WARN("REQ rejected: missing or invalid subscription ID");
}
} else if (strcmp(msg_type, "COUNT") == 0) {
// Check NIP-42 authentication for COUNT requests if required
@@ -776,7 +786,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
send_nip42_auth_challenge(wsi, pss);
} else {
send_notice_message(wsi, "NIP-42 authentication required for count requests");
log_warning("COUNT rejected: NIP-42 authentication required");
DEBUG_WARN("COUNT rejected: NIP-42 authentication required");
}
cJSON_Delete(json);
free(message);
@@ -803,7 +813,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
char filter_error[512] = {0};
if (!validate_filter_array(filters, filter_error, sizeof(filter_error))) {
send_notice_message(wsi, filter_error);
log_warning("COUNT rejected: invalid filters");
DEBUG_WARN("COUNT rejected: invalid filters");
record_malformed_request(pss);
cJSON_Delete(filters);
cJSON_Delete(json);
@@ -825,7 +835,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Validate subscription ID before processing
if (!subscription_id) {
send_notice_message(wsi, "error: invalid subscription ID in CLOSE");
log_warning("CLOSE rejected: NULL subscription ID");
DEBUG_WARN("CLOSE rejected: NULL subscription ID");
cJSON_Delete(json);
free(message);
return 0;
@@ -835,7 +845,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
size_t id_len = strlen(subscription_id);
if (id_len == 0 || id_len >= SUBSCRIPTION_ID_MAX_LENGTH) {
send_notice_message(wsi, "error: subscription ID too long or empty in CLOSE");
log_warning("CLOSE rejected: invalid subscription ID length");
DEBUG_WARN("CLOSE rejected: invalid subscription ID length");
cJSON_Delete(json);
free(message);
return 0;
@@ -854,7 +864,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
if (!valid_id) {
send_notice_message(wsi, "error: invalid characters in subscription ID for CLOSE");
log_warning("CLOSE rejected: invalid characters in subscription ID");
DEBUG_WARN("CLOSE rejected: invalid characters in subscription ID");
cJSON_Delete(json);
free(message);
return 0;
@@ -884,7 +894,7 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
// Subscription closed
} else {
send_notice_message(wsi, "error: missing or invalid subscription ID in CLOSE");
log_warning("CLOSE rejected: missing or invalid subscription ID");
DEBUG_WARN("CLOSE rejected: missing or invalid subscription ID");
}
} else if (strcmp(msg_type, "AUTH") == 0) {
// Handle NIP-42 AUTH message
@@ -899,17 +909,17 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
handle_nip42_auth_signed_event(wsi, pss, auth_payload);
} else {
send_notice_message(wsi, "Invalid AUTH message format");
log_warning("Received AUTH message with invalid payload type");
DEBUG_WARN("Received AUTH message with invalid payload type");
}
} else {
send_notice_message(wsi, "AUTH message requires payload");
log_warning("Received AUTH message without payload");
DEBUG_WARN("Received AUTH message without payload");
}
} else {
// Unknown message type
char unknown_msg[128];
snprintf(unknown_msg, sizeof(unknown_msg), "Unknown message type: %.32s", msg_type);
log_warning(unknown_msg);
DEBUG_WARN(unknown_msg);
send_notice_message(wsi, "Unknown message type");
}
}
@@ -922,24 +932,27 @@ static int nostr_relay_callback(struct lws *wsi, enum lws_callback_reasons reaso
break;
case LWS_CALLBACK_CLOSED:
DEBUG_TRACE("WebSocket connection closed");
DEBUG_LOG("WebSocket connection closed from %s", pss ? pss->client_ip : "unknown");
// Clean up session subscriptions
if (pss) {
pthread_mutex_lock(&pss->session_lock);
struct subscription* sub = pss->subscriptions;
while (sub) {
struct subscription* next = sub->session_next;
remove_subscription_from_manager(sub->id, wsi);
sub = next;
}
pss->subscriptions = NULL;
pss->subscription_count = 0;
pthread_mutex_unlock(&pss->session_lock);
pthread_mutex_destroy(&pss->session_lock);
}
DEBUG_TRACE("WebSocket connection cleanup complete");
break;
default:
@@ -1041,13 +1054,13 @@ int start_websocket_relay(int port_override, int strict_port) {
char error_msg[256];
snprintf(error_msg, sizeof(error_msg),
"Strict port mode: port %d is not available", actual_port);
log_error(error_msg);
DEBUG_ERROR(error_msg);
return -1;
} else if (port_attempts < max_port_attempts) {
char retry_msg[256];
snprintf(retry_msg, sizeof(retry_msg), "Port %d is in use, trying port %d (attempt %d/%d)",
actual_port, actual_port + 1, port_attempts + 1, max_port_attempts);
log_warning(retry_msg);
DEBUG_WARN(retry_msg);
actual_port++;
continue;
} else {
@@ -1055,7 +1068,7 @@ int start_websocket_relay(int port_override, int strict_port) {
snprintf(error_msg, sizeof(error_msg),
"Failed to find available port after %d attempts (tried ports %d-%d)",
max_port_attempts, configured_port, actual_port);
log_error(error_msg);
DEBUG_ERROR(error_msg);
return -1;
}
}
@@ -1077,14 +1090,14 @@ int start_websocket_relay(int port_override, int strict_port) {
char lws_error_msg[256];
snprintf(lws_error_msg, sizeof(lws_error_msg),
"libwebsockets failed to bind to port %d (errno: %d)", actual_port, errno_saved);
log_warning(lws_error_msg);
DEBUG_WARN(lws_error_msg);
port_attempts++;
if (strict_port) {
char error_msg[256];
snprintf(error_msg, sizeof(error_msg),
"Strict port mode: failed to bind to port %d", actual_port);
log_error(error_msg);
DEBUG_ERROR(error_msg);
break;
} else if (port_attempts < max_port_attempts) {
actual_port++;
@@ -1100,7 +1113,7 @@ int start_websocket_relay(int port_override, int strict_port) {
snprintf(error_msg, sizeof(error_msg),
"Failed to create libwebsockets context after %d attempts. Last attempted port: %d",
port_attempts, actual_port);
log_error(error_msg);
DEBUG_ERROR(error_msg);
perror("libwebsockets creation error");
return -1;
}
@@ -1110,7 +1123,7 @@ int start_websocket_relay(int port_override, int strict_port) {
snprintf(startup_msg, sizeof(startup_msg),
"WebSocket relay started on ws://127.0.0.1:%d (configured port %d was unavailable)",
actual_port, configured_port);
log_warning(startup_msg);
DEBUG_WARN(startup_msg);
} else {
snprintf(startup_msg, sizeof(startup_msg), "WebSocket relay started on ws://127.0.0.1:%d", actual_port);
}
@@ -1120,7 +1133,7 @@ int start_websocket_relay(int port_override, int strict_port) {
int result = lws_service(ws_context, 1000);
if (result < 0) {
log_error("libwebsockets service error");
DEBUG_ERROR("libwebsockets service error");
break;
}
}
@@ -1304,7 +1317,7 @@ int handle_count_message(const char* sub_id, cJSON* filters, struct lws *wsi, st
(void)pss; // Suppress unused parameter warning
if (!cJSON_IsArray(filters)) {
log_error("COUNT filters is not an array");
DEBUG_ERROR("COUNT filters is not an array");
return 0;
}
@@ -1319,7 +1332,7 @@ int handle_count_message(const char* sub_id, cJSON* filters, struct lws *wsi, st
for (int i = 0; i < cJSON_GetArraySize(filters); i++) {
cJSON* filter = cJSON_GetArrayItem(filters, i);
if (!filter || !cJSON_IsObject(filter)) {
log_warning("Invalid filter object in COUNT");
DEBUG_WARN("Invalid filter object in COUNT");
continue;
}
@@ -1566,7 +1579,7 @@ int handle_count_message(const char* sub_id, cJSON* filters, struct lws *wsi, st
if (rc != SQLITE_OK) {
char error_msg[256];
snprintf(error_msg, sizeof(error_msg), "Failed to prepare COUNT query: %s", sqlite3_errmsg(g_db));
log_error(error_msg);
DEBUG_ERROR(error_msg);
continue;
}
@@ -1661,7 +1674,7 @@ int is_client_rate_limited_for_malformed_requests(struct per_session_data *pss)
if (pss->malformed_request_count >= MAX_MALFORMED_REQUESTS_PER_HOUR) {
// Block for the specified duration
pss->malformed_request_blocked_until = now + MALFORMED_REQUEST_BLOCK_DURATION;
log_warning("Client rate limited for malformed requests");
DEBUG_WARN("Client rate limited for malformed requests");
return 1;
}