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

v0.7.4 - Remove excessive debug logging from entire codebase - preserve user-facing error logging

Browse Source
This commit is contained in:
Your Name
2025-10-10 10:21:30 -04:00
parent b89c011ad5
commit c90676d2b2
15 changed files with 96 additions and 762 deletions
Download Patch File Download Diff File Expand all files Collapse all files

176
src/request_validator.c
View File

@@ -139,21 +139,6 @@ struct {
char reason[500]; // specific reason string
} g_last_rule_violation = {0};
/**
* Helper function for consistent debug logging to main relay.log file
*/
static void validator_debug_log(const char *message) {
FILE *relay_log = fopen("relay.log", "a");
if (relay_log) {
// Use same format as main logging system
time_t now = time(NULL);
struct tm *tm_info = localtime(&now);
char timestamp[20];
strftime(timestamp, sizeof(timestamp), "%Y-%m-%d %H:%M:%S", tm_info);
fprintf(relay_log, "[%s] [DEBUG] %s", timestamp, message);
fclose(relay_log);
}
}
//=============================================================================
// FORWARD DECLARATIONS
@@ -188,16 +173,12 @@ int ginxsom_request_validator_init(const char *db_path, const char *app_name) {
// Initialize nostr_core_lib if not already done
if (nostr_crypto_init() != NOSTR_SUCCESS) {
validator_debug_log(
"VALIDATOR: Failed to initialize nostr crypto system\n");
return NOSTR_ERROR_CRYPTO_INIT;
}
// Load initial configuration from database
int result = reload_auth_config();
if (result != NOSTR_SUCCESS) {
validator_debug_log(
"VALIDATOR: Failed to load configuration from database\n");
return result;
}
@@ -215,8 +196,6 @@ int ginxsom_request_validator_init(const char *db_path, const char *app_name) {
g_challenge_manager.last_cleanup = time(NULL);
g_validator_initialized = 1;
validator_debug_log(
"VALIDATOR: Request validator initialized successfully\n");
return NOSTR_SUCCESS;
}
@@ -257,20 +236,17 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
// 1. Null Pointer Checks - Reject malformed requests instantly
if (!json_string || json_length == 0) {
validator_debug_log("VALIDATOR_DEBUG: STEP 1 FAILED - Null input\n");
return NOSTR_ERROR_INVALID_INPUT;
}
// 2. Initialization Check - Verify system is properly initialized
if (!g_validator_initialized) {
validator_debug_log("VALIDATOR_DEBUG: STEP 2 FAILED - Validator not initialized\n");
return NOSTR_ERROR_INVALID_INPUT;
}
// 3. Parse JSON string to cJSON event object
cJSON *event = cJSON_ParseWithLength(json_string, json_length);
if (!event) {
validator_debug_log("VALIDATOR_DEBUG: STEP 3 FAILED - Failed to parse JSON event\n");
return NOSTR_ERROR_INVALID_INPUT;
}
@@ -290,20 +266,14 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
!tags || !cJSON_IsArray(tags) ||
!content || !cJSON_IsString(content) ||
!sig || !cJSON_IsString(sig)) {
validator_debug_log("VALIDATOR_DEBUG: STEP 4 FAILED - Invalid event structure\n");
cJSON_Delete(event);
return NOSTR_ERROR_INVALID_INPUT;
}
int event_kind = (int)cJSON_GetNumberValue(kind);
// 5. Check configuration using unified cache
int auth_required = nostr_auth_rules_enabled();
char config_msg[256];
sprintf(config_msg, "VALIDATOR_DEBUG: STEP 5 PASSED - Event kind: %d, auth_required: %d\n",
event_kind, auth_required);
validator_debug_log(config_msg);
/////////////////////////////////////////////////////////////////////
// PHASE 2: NOSTR EVENT VALIDATION
@@ -312,39 +282,26 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
// 6. Nostr Event Structure Validation using nostr_core_lib
int validation_result = nostr_validate_event(event);
if (validation_result != NOSTR_SUCCESS) {
char validation_msg[256];
sprintf(validation_msg, "VALIDATOR_DEBUG: STEP 6 FAILED - NOSTR event validation failed (error=%d)\n",
validation_result);
validator_debug_log(validation_msg);
cJSON_Delete(event);
return validation_result;
}
validator_debug_log("VALIDATOR_DEBUG: STEP 6 PASSED - Event structure and signature valid\n");
// 7. Extract pubkey for rule evaluation
const char *event_pubkey = cJSON_GetStringValue(pubkey);
if (!event_pubkey || strlen(event_pubkey) != 64) {
validator_debug_log("VALIDATOR_DEBUG: STEP 7 FAILED - Invalid pubkey format\n");
cJSON_Delete(event);
return NOSTR_ERROR_EVENT_INVALID_PUBKEY;
}
char pubkey_msg[256];
sprintf(pubkey_msg, "VALIDATOR_DEBUG: STEP 7 PASSED - Extracted pubkey: %.16s...\n", event_pubkey);
validator_debug_log(pubkey_msg);
/////////////////////////////////////////////////////////////////////
// PHASE 3: EVENT KIND SPECIFIC VALIDATION
/////////////////////////////////////////////////////////////////////
// 8. Handle NIP-42 authentication challenge events (kind 22242)
if (event_kind == 22242) {
validator_debug_log("VALIDATOR_DEBUG: STEP 8 - Processing NIP-42 challenge response\n");
// Check NIP-42 mode using unified cache
const char* nip42_enabled = get_config_value("nip42_auth_enabled");
if (nip42_enabled && strcmp(nip42_enabled, "false") == 0) {
validator_debug_log("VALIDATOR_DEBUG: STEP 8 FAILED - NIP-42 is disabled\n");
free((char*)nip42_enabled);
cJSON_Delete(event);
return NOSTR_ERROR_NIP42_DISABLED;
@@ -353,7 +310,6 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
// TODO: Implement full NIP-42 challenge validation
// For now, accept all valid NIP-42 events
validator_debug_log("VALIDATOR_DEBUG: STEP 8 PASSED - NIP-42 challenge response accepted\n");
cJSON_Delete(event);
return NOSTR_SUCCESS;
}
@@ -364,10 +320,8 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
// 9. Check if authentication rules are enabled
if (!auth_required) {
validator_debug_log("VALIDATOR_DEBUG: STEP 9 - Authentication disabled, skipping database auth rules\n");
} else {
// 10. Check database authentication rules (only if auth enabled)
validator_debug_log("VALIDATOR_DEBUG: STEP 10 - Checking database authentication rules\n");
// Create operation string with event kind for more specific rule matching
char operation_str[64];
@@ -379,17 +333,10 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
// If generic event check fails, try specific event kind check
rules_result = check_database_auth_rules(event_pubkey, operation_str, NULL);
if (rules_result != NOSTR_SUCCESS) {
char rules_msg[256];
sprintf(rules_msg, "VALIDATOR_DEBUG: STEP 10 FAILED - Database rules denied request (kind=%d)\n", event_kind);
validator_debug_log(rules_msg);
cJSON_Delete(event);
return rules_result;
}
}
char rules_success_msg[256];
sprintf(rules_success_msg, "VALIDATOR_DEBUG: STEP 10 PASSED - Database rules allow request (kind=%d)\n", event_kind);
validator_debug_log(rules_success_msg);
}
/////////////////////////////////////////////////////////////////////
@@ -404,44 +351,30 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
pthread_mutex_unlock(&g_unified_cache.cache_lock);
if (pow_enabled && pow_min_difficulty > 0) {
validator_debug_log("VALIDATOR_DEBUG: STEP 11 - Validating NIP-13 Proof of Work\n");
nostr_pow_result_t pow_result;
int pow_validation_result = nostr_validate_pow(event, pow_min_difficulty,
pow_validation_flags, &pow_result);
if (pow_validation_result != NOSTR_SUCCESS) {
char pow_msg[256];
sprintf(pow_msg, "VALIDATOR_DEBUG: STEP 11 FAILED - PoW validation failed (error=%d, difficulty=%d/%d)\n",
pow_validation_result, pow_result.actual_difficulty, pow_min_difficulty);
validator_debug_log(pow_msg);
cJSON_Delete(event);
return pow_validation_result;
}
char pow_success_msg[256];
sprintf(pow_success_msg, "VALIDATOR_DEBUG: STEP 11 PASSED - PoW validated (difficulty=%d, target=%d)\n",
pow_result.actual_difficulty, pow_result.committed_target);
validator_debug_log(pow_success_msg);
} else {
validator_debug_log("VALIDATOR_DEBUG: STEP 11 SKIPPED - PoW validation disabled or min_difficulty=0\n");
}
// 12. NIP-40 Expiration validation
// Always check expiration tags if present (following NIP-40 specification)
validator_debug_log("VALIDATOR_DEBUG: STEP 12 - Starting NIP-40 Expiration validation\n");
cJSON *expiration_tag = NULL;
cJSON *tags_array = cJSON_GetObjectItem(event, "tags");
if (tags_array && cJSON_IsArray(tags_array)) {
cJSON *tag = NULL;
cJSON_ArrayForEach(tag, tags_array) {
if (!cJSON_IsArray(tag)) continue;
cJSON *tag_name = cJSON_GetArrayItem(tag, 0);
if (!tag_name || !cJSON_IsString(tag_name)) continue;
const char *tag_name_str = cJSON_GetStringValue(tag_name);
if (strcmp(tag_name_str, "expiration") == 0) {
cJSON *tag_value = cJSON_GetArrayItem(tag, 1);
@@ -452,57 +385,40 @@ int nostr_validate_unified_request(const char* json_string, size_t json_length)
}
}
}
if (expiration_tag) {
const char *expiration_str = cJSON_GetStringValue(expiration_tag);
// Validate that the expiration string contains only digits (and optional leading whitespace)
const char* p = expiration_str;
// Skip leading whitespace
while (*p == ' ' || *p == '\t') p++;
// Check if we have at least one digit
if (*p == '\0') {
validator_debug_log("VALIDATOR_DEBUG: STEP 12 SKIPPED - Empty expiration tag value, ignoring\n");
} else {
// Validate that all remaining characters are digits
const char* digit_start = p;
while (*p >= '0' && *p <= '9') p++;
// If we didn't consume the entire string or found no digits, it's malformed
if (*p != '\0' || p == digit_start) {
char malformed_msg[256];
sprintf(malformed_msg, "VALIDATOR_DEBUG: STEP 12 SKIPPED - Malformed expiration tag value '%.32s', ignoring\n",
expiration_str);
validator_debug_log(malformed_msg);
} else {
// Valid numeric string, parse and check expiration
time_t expiration_time = (time_t)atol(expiration_str);
time_t now = time(NULL);
int grace_period = get_config_int("nip40_expiration_grace_period", 60);
if (expiration_time > 0 && now > expiration_time + grace_period) {
char exp_msg[256];
sprintf(exp_msg, "VALIDATOR_DEBUG: STEP 12 FAILED - Event expired (now=%ld, exp=%ld, grace=%d)\n",
(long)now, (long)expiration_time, grace_period);
validator_debug_log(exp_msg);
cJSON_Delete(event);
return NOSTR_ERROR_EVENT_EXPIRED;
}
char exp_success_msg[256];
sprintf(exp_success_msg, "VALIDATOR_DEBUG: STEP 12 PASSED - Event not expired (exp=%ld, now=%ld)\n",
(long)expiration_time, (long)now);
validator_debug_log(exp_success_msg);
}
}
} else {
validator_debug_log("VALIDATOR_DEBUG: STEP 12 SKIPPED - No expiration tag found\n");
}
// All validations passed
validator_debug_log("VALIDATOR_DEBUG: STEP 13 PASSED - All validations complete, event ACCEPTED\n");
cJSON_Delete(event);
return NOSTR_SUCCESS;
}
@@ -578,7 +494,6 @@ void nostr_request_result_free_file_data(nostr_request_result_t *result) {
void nostr_request_validator_force_cache_refresh(void) {
// Use unified cache refresh from config.c
force_config_cache_refresh();
validator_debug_log("VALIDATOR: Cache forcibly invalidated via unified cache\n");
}
/**
@@ -586,7 +501,6 @@ void nostr_request_validator_force_cache_refresh(void) {
*/
static int reload_auth_config(void) {
// Configuration is now handled by the unified cache in config.c
validator_debug_log("VALIDATOR: Using unified cache system for configuration\n");
return NOSTR_SUCCESS;
}
@@ -598,35 +512,23 @@ static int reload_auth_config(void) {
* Check database authentication rules for the request
* Implements the 6-step rule evaluation engine from AUTH_API.md
*/
int check_database_auth_rules(const char *pubkey, const char *operation,
int check_database_auth_rules(const char *pubkey, const char *operation __attribute__((unused)),
const char *resource_hash) {
sqlite3 *db = NULL;
sqlite3_stmt *stmt = NULL;
int rc;
if (!pubkey) {
validator_debug_log(
"VALIDATOR_DEBUG: RULES ENGINE - Missing pubkey for rule evaluation\n");
return NOSTR_ERROR_INVALID_INPUT;
}
char rules_msg[256];
sprintf(rules_msg,
"VALIDATOR_DEBUG: RULES ENGINE - Checking rules for pubkey=%.32s..., "
"operation=%s\n",
pubkey, operation ? operation : "NULL");
validator_debug_log(rules_msg);
// Open database using global database path
if (strlen(g_database_path) == 0) {
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - No database path available\n");
return NOSTR_SUCCESS; // Default allow on DB error
}
rc = sqlite3_open_v2(g_database_path, &db, SQLITE_OPEN_READONLY, NULL);
if (rc != SQLITE_OK) {
validator_debug_log(
"VALIDATOR_DEBUG: RULES ENGINE - Failed to open database\n");
return NOSTR_SUCCESS; // Default allow on DB error
}
@@ -640,13 +542,6 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
if (sqlite3_step(stmt) == SQLITE_ROW) {
const char *action = (const char *)sqlite3_column_text(stmt, 1);
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 1 FAILED - "
"Pubkey blacklisted\n");
char blacklist_msg[256];
sprintf(blacklist_msg,
"VALIDATOR_DEBUG: RULES ENGINE - Blacklist rule matched: action=%s\n",
action ? action : "deny");
validator_debug_log(blacklist_msg);
// Set specific violation details for status code mapping
strcpy(g_last_rule_violation.violation_type, "pubkey_blacklist");
@@ -659,8 +554,6 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
}
sqlite3_finalize(stmt);
}
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 1 PASSED - Pubkey "
"not blacklisted\n");
// Step 2: Check hash blacklist
if (resource_hash) {
@@ -673,14 +566,6 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
if (sqlite3_step(stmt) == SQLITE_ROW) {
const char *action = (const char *)sqlite3_column_text(stmt, 1);
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 2 FAILED - "
"Hash blacklisted\n");
char hash_blacklist_msg[256];
sprintf(
hash_blacklist_msg,
"VALIDATOR_DEBUG: RULES ENGINE - Hash blacklist rule matched: action=%s\n",
action ? action : "deny");
validator_debug_log(hash_blacklist_msg);
// Set specific violation details for status code mapping
strcpy(g_last_rule_violation.violation_type, "hash_blacklist");
@@ -693,11 +578,6 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
}
sqlite3_finalize(stmt);
}
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 2 PASSED - Hash "
"not blacklisted\n");
} else {
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 2 SKIPPED - No "
"resource hash provided\n");
}
// Step 3: Check pubkey whitelist
@@ -709,22 +589,12 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
sqlite3_bind_text(stmt, 1, pubkey, -1, SQLITE_STATIC);
if (sqlite3_step(stmt) == SQLITE_ROW) {
const char *action = (const char *)sqlite3_column_text(stmt, 1);
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 3 PASSED - "
"Pubkey whitelisted\n");
char whitelist_msg[256];
sprintf(whitelist_msg,
"VALIDATOR_DEBUG: RULES ENGINE - Whitelist rule matched: action=%s\n",
action ? action : "allow");
validator_debug_log(whitelist_msg);
sqlite3_finalize(stmt);
sqlite3_close(db);
return NOSTR_SUCCESS; // Allow whitelisted pubkey
}
sqlite3_finalize(stmt);
}
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 3 FAILED - Pubkey "
"not whitelisted\n");
// Step 4: Check if any whitelist rules exist - if yes, deny by default
const char *whitelist_exists_sql =
@@ -735,9 +605,6 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
if (sqlite3_step(stmt) == SQLITE_ROW) {
int whitelist_count = sqlite3_column_int(stmt, 0);
if (whitelist_count > 0) {
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 4 FAILED - "
"Whitelist exists but pubkey not in it\n");
// Set specific violation details for status code mapping
strcpy(g_last_rule_violation.violation_type, "whitelist_violation");
strcpy(g_last_rule_violation.reason,
@@ -750,12 +617,8 @@ int check_database_auth_rules(const char *pubkey, const char *operation,
}
sqlite3_finalize(stmt);
}
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 4 PASSED - No "
"whitelist restrictions apply\n");
sqlite3_close(db);
validator_debug_log("VALIDATOR_DEBUG: RULES ENGINE - STEP 5 PASSED - All "
"rule checks completed, default ALLOW\n");
return NOSTR_SUCCESS; // Default allow if no restrictive rules matched
}
@@ -821,11 +684,6 @@ static void cleanup_expired_challenges(void) {
}
g_challenge_manager.last_cleanup = now;
char cleanup_msg[256];
sprintf(cleanup_msg, "NIP-42: Cleaned up challenges, %d active remaining\n",
active_count);
validator_debug_log(cleanup_msg);
}
/**
@@ -877,12 +735,6 @@ static int store_challenge(const char *challenge_id, const char *client_ip) {
entry->expires_at = now + g_challenge_manager.timeout_seconds;
entry->active = 1;
char store_msg[256];
sprintf(store_msg,
"NIP-42: Stored challenge %.16s... (expires in %d seconds)\n",
challenge_id, g_challenge_manager.timeout_seconds);
validator_debug_log(store_msg);
return NOSTR_SUCCESS;
}