debug: crypto_ctx session_key логгирование — CRYPTO_CONN_READY, CRYPTO_ON_UP, CRYPTO_DECRYPT_OK, DECRYPT_FAIL+seskey

src/transport_layer/etcp.c

@@ -297,11 +297,23 @@ static void etcp_fire_conn_status(struct ETCP_CONN* etcp, int status) {
 
 static void etcp_on_up(struct ETCP_CONN* etcp) {
     DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] Connection UP (links_up=%d initialized=%d)", etcp->log_name, etcp->links_up, etcp->initialized);
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_ON_UP_BEFORE: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x",
+                etcp->log_name,
+                etcp->crypto_ctx.session_key[0], etcp->crypto_ctx.session_key[1],
+                etcp->crypto_ctx.session_key[2], etcp->crypto_ctx.session_key[3],
+                etcp->crypto_ctx.peer_public_key[0], etcp->crypto_ctx.peer_public_key[1],
+                etcp->crypto_ctx.peer_public_key[2], etcp->crypto_ctx.peer_public_key[3]);
     etcp->callbacks_running = 1;
     struct etcp_cbk_entry* cbe = etcp->up_cbks;
     while (cbe) { struct etcp_cbk_entry* n = cbe->next; cbe->fn(etcp, cbe->arg); cbe = n; }
     etcp_fire_conn_status(etcp, ETCP_CONN_STATUS_UP);
     etcp->callbacks_running = 0;
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_ON_UP_AFTER: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x",
+                etcp->log_name,
+                etcp->crypto_ctx.session_key[0], etcp->crypto_ctx.session_key[1],
+                etcp->crypto_ctx.session_key[2], etcp->crypto_ctx.session_key[3],
+                etcp->crypto_ctx.peer_public_key[0], etcp->crypto_ctx.peer_public_key[1],
+                etcp->crypto_ctx.peer_public_key[2], etcp->crypto_ctx.peer_public_key[3]);
 }
 
 static void etcp_on_down(struct ETCP_CONN* etcp) {
@@ -592,6 +604,17 @@ void etcp_conn_ready(struct ETCP_CONN* conn) {
     conn->reset_done = 1;
     if (conn->tx_state == 0) { conn->tx_state = ETCP_TX_STATE_DATA_WAIT; }
     DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] Connection ready", conn->log_name);
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_CONN_READY: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x my_pub=%02x%02x%02x%02x links=%p",
+                conn->log_name,
+                conn->crypto_ctx.session_key[0], conn->crypto_ctx.session_key[1],
+                conn->crypto_ctx.session_key[2], conn->crypto_ctx.session_key[3],
+                conn->crypto_ctx.peer_public_key[0], conn->crypto_ctx.peer_public_key[1],
+                conn->crypto_ctx.peer_public_key[2], conn->crypto_ctx.peer_public_key[3],
+                conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[0] : 0,
+                conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[1] : 0,
+                conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[2] : 0,
+                conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[3] : 0,
+                (void*)conn->links);
 
     etcp_conn_queue_set_ready(conn);
 }

src/transport_layer/etcp_connections.c

@@ -1555,12 +1555,19 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
                    recv_len, (unsigned long long)link->etcp->crypto_ctx.rx_counter);
         sc_status_t dec_rc = sc_decrypt(&link->etcp->crypto_ctx, data, recv_len, (uint8_t*)&pkt->timestamp, &pkt_len);
         if (!dec_rc) {
+            DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_DECRYPT_OK: log=%s seskey=%02x%02x%02x%02x rx=%llu pkt_len=%zu",
+                        link->etcp->log_name,
+                        link->etcp->crypto_ctx.session_key[0], link->etcp->crypto_ctx.session_key[1],
+                        link->etcp->crypto_ctx.session_key[2], link->etcp->crypto_ctx.session_key[3],
+                        (unsigned long long)link->etcp->crypto_ctx.rx_counter, pkt_len);
             goto process_decrypted;
         }
-            DEBUG_INFO(DEBUG_CATEGORY_ETCP, "etcp: DECRYPT FAIL rc=%d link=%p log=%s sess=%d link_state=%d keepalive=%d enc_errs=%zu my_pub=%016llx peer_pub=%016llx",
+            DEBUG_INFO(DEBUG_CATEGORY_ETCP, "etcp: DECRYPT FAIL rc=%d link=%p log=%s sess=%d link_state=%d keepalive=%d enc_errs=%zu my_pub=%016llx peer_pub=%016llx seskey=%02x%02x%02x%02x",
                        dec_rc, link, link->etcp->log_name, link->etcp->crypto_ctx.session_ready,
                        link->link_state, link->recv_keepalive, link->encrypt_errors,
-                       *(uint64_t*)link->etcp->crypto_ctx.pk->public_key, *(uint64_t*)link->etcp->crypto_ctx.peer_public_key);
+                       *(uint64_t*)link->etcp->crypto_ctx.pk->public_key, *(uint64_t*)link->etcp->crypto_ctx.peer_public_key,
+                       link->etcp->crypto_ctx.session_key[0], link->etcp->crypto_ctx.session_key[1],
+                       link->etcp->crypto_ctx.session_key[2], link->etcp->crypto_ctx.session_key[3]);
     } else {
         DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "SKIP normal decrypt: link=%p session_ready=%d — trying init decrypt",
                     link, link && link->etcp ? link->etcp->crypto_ctx.session_ready : -1);
@@ -1703,6 +1710,16 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
         conn=etcp_connection_create(e_sock->instance,"");
         if (!conn) { errorcode=55; DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "failed to create connection"); goto ec_fr; }
         memcpy(&conn->crypto_ctx, &sc, sizeof(sc));
+        DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_CTX_INIT: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x my_priv=%02x%02x%02x%02x",
+                    conn->log_name,
+                    conn->crypto_ctx.session_key[0], conn->crypto_ctx.session_key[1],
+                    conn->crypto_ctx.session_key[2], conn->crypto_ctx.session_key[3],
+                    conn->crypto_ctx.peer_public_key[0], conn->crypto_ctx.peer_public_key[1],
+                    conn->crypto_ctx.peer_public_key[2], conn->crypto_ctx.peer_public_key[3],
+                    conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[0] : 0,
+                    conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[1] : 0,
+                    conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[2] : 0,
+                    conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[3] : 0);
         etcp_conn_set_peer_node_id(conn, peer_id);
         DEBUG_INFO(DEBUG_CATEGORY_ETCP, "New connection received on socket %s: log_name=%s peer_id=%lu peer:%s", e_sock->name, conn->log_name, (unsigned long)peer_id, sockaddr_storage_to_str(&addr).str);
         DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "New connection from %s peer_id=%ld etcp=%p total=%d",