fix: Report failure to DHT bootstrap back to the client.

Also reduce log verbosity a bit.

Author: iphydf

.github/workflows/ci.yml

@@ -4,6 +4,11 @@ on:
   pull_request:
     branches: [master]
 
+# Cancel old PR builds when pushing new commits.
+concurrency:
+  group: build-${{ github.event.pull_request.number || github.ref }}
+  cancel-in-progress: true
+
 jobs:
   common:
     uses: TokTok/ci-tools/.github/workflows/common-ci.yml@master

auto_tests/dht_test.c

@@ -626,9 +626,9 @@ static void test_dht_create_packet(void)
 
 #define MAX_COUNT 3
 
-static void dht_pack_unpack(const Node_format *nodes, size_t size, uint8_t *data, size_t length)
+static void dht_pack_unpack(const Logger *logger, const Node_format *nodes, size_t size, uint8_t *data, size_t length)
 {
-    int16_t packed_size = pack_nodes(data, length, nodes, size);
+    int16_t packed_size = pack_nodes(logger, data, length, nodes, size);
     ck_assert_msg(packed_size != -1, "Wrong pack_nodes result");
 
     uint16_t processed = 0;
@@ -677,6 +677,10 @@ static void random_ip(IP_Port *ipp, int family)
 
 static void test_dht_node_packing(void)
 {
+    Logger *log = logger_new();
+    uint32_t index = 1;
+    logger_callback_log(log, (logger_cb *)print_debug_log, nullptr, &index);
+
     const uint16_t length = MAX_COUNT * PACKED_NODES_SIZE;
     uint8_t *data = (uint8_t *)malloc(length);
 
@@ -690,28 +694,29 @@ static void test_dht_node_packing(void)
     random_ip(&nodes[0].ip_port, TOX_AF_INET);
     random_ip(&nodes[1].ip_port, TOX_AF_INET);
     random_ip(&nodes[2].ip_port, TOX_AF_INET);
-    dht_pack_unpack(nodes, 3, data, length);
+    dht_pack_unpack(log, nodes, 3, data, length);
 
     random_ip(&nodes[0].ip_port, TOX_AF_INET);
     random_ip(&nodes[1].ip_port, TOX_AF_INET);
     random_ip(&nodes[2].ip_port, TCP_INET);
-    dht_pack_unpack(nodes, 3, data, length);
+    dht_pack_unpack(log, nodes, 3, data, length);
 
     random_ip(&nodes[0].ip_port, TOX_AF_INET);
     random_ip(&nodes[1].ip_port, TOX_AF_INET6);
     random_ip(&nodes[2].ip_port, TCP_INET6);
-    dht_pack_unpack(nodes, 3, data, length);
+    dht_pack_unpack(log, nodes, 3, data, length);
 
     random_ip(&nodes[0].ip_port, TCP_INET);
     random_ip(&nodes[1].ip_port, TCP_INET6);
     random_ip(&nodes[2].ip_port, TCP_INET);
-    dht_pack_unpack(nodes, 3, data, length);
+    dht_pack_unpack(log, nodes, 3, data, length);
 
     random_ip(&nodes[0].ip_port, TOX_AF_INET6);
     random_ip(&nodes[1].ip_port, TOX_AF_INET6);
     random_ip(&nodes[2].ip_port, TOX_AF_INET6);
-    dht_pack_unpack(nodes, 3, data, length);
+    dht_pack_unpack(log, nodes, 3, data, length);
 
+    logger_kill(log);
     free(data);
 }
 

other/bootstrap_daemon/docker/tox-bootstrapd.sha256

@@ -1 +1 @@
-e79b800f95e9dd714128de63824483facac7487788d57a9c89ef2e1c39d3588f  /usr/local/bin/tox-bootstrapd
+b899ee4325e854deafa435b697c0e37430222f4f87537f4b12021eb40d12857d  /usr/local/bin/tox-bootstrapd

toxav/toxav.c

@@ -973,13 +973,13 @@ bool toxav_video_send_frame(ToxAV *av, uint32_t friend_number, uint16_t width, u
     if (call->video_rtp->ssrc < VIDEO_SEND_X_KEYFRAMES_FIRST) {
         // Key frame flag for first frames
         vpx_encode_flags = VPX_EFLAG_FORCE_KF;
-        LOGGER_INFO(av->m->log, "I_FRAME_FLAG:%d only-i-frame mode", call->video_rtp->ssrc);
+        LOGGER_DEBUG(av->m->log, "I_FRAME_FLAG:%d only-i-frame mode", call->video_rtp->ssrc);
 
         ++call->video_rtp->ssrc;
     } else if (call->video_rtp->ssrc == VIDEO_SEND_X_KEYFRAMES_FIRST) {
         // normal keyframe placement
         vpx_encode_flags = 0;
-        LOGGER_INFO(av->m->log, "I_FRAME_FLAG:%d normal mode", call->video_rtp->ssrc);
+        LOGGER_DEBUG(av->m->log, "I_FRAME_FLAG:%d normal mode", call->video_rtp->ssrc);
 
         ++call->video_rtp->ssrc;
     }

toxcore/DHT.c

@@ -422,7 +422,7 @@ int packed_node_size(Family ip_family)
  * Returns size of packed IP_Port data on success
  * Return -1 on failure.
  */
-int pack_ip_port(uint8_t *data, uint16_t length, const IP_Port *ip_port)
+int pack_ip_port(const Logger *logger, uint8_t *data, uint16_t length, const IP_Port *ip_port)
 {
     if (data == nullptr) {
         return -1;
@@ -445,6 +445,10 @@ int pack_ip_port(uint8_t *data, uint16_t length, const IP_Port *ip_port)
         is_ipv4 = false;
         net_family = TOX_TCP_INET6;
     } else {
+        char ip_str[IP_NTOA_LEN];
+        // TODO(iphydf): Find out why we're trying to pack invalid IPs, stop
+        // doing that, and turn this into an error.
+        LOGGER_TRACE(logger, "cannot pack invalid IP: %s", ip_ntoa(&ip_port->ip, ip_str, sizeof(ip_str)));
         return -1;
     }
 
@@ -576,12 +580,12 @@ int unpack_ip_port(IP_Port *ip_port, const uint8_t *data, uint16_t length, bool
  * return length of packed nodes on success.
  * return -1 on failure.
  */
-int pack_nodes(uint8_t *data, uint16_t length, const Node_format *nodes, uint16_t number)
+int pack_nodes(const Logger *logger, uint8_t *data, uint16_t length, const Node_format *nodes, uint16_t number)
 {
     uint32_t packed_length = 0;
 
     for (uint32_t i = 0; i < number && packed_length < length; ++i) {
-        const int ipp_size = pack_ip_port(data + packed_length, length - packed_length, &nodes[i].ip_port);
+        const int ipp_size = pack_ip_port(logger, data + packed_length, length - packed_length, &nodes[i].ip_port);
 
         if (ipp_size == -1) {
             return -1;
@@ -1325,7 +1329,7 @@ bool dht_getnodes(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key, c
     memcpy(receiver.public_key, public_key, CRYPTO_PUBLIC_KEY_SIZE);
     receiver.ip_port = *ip_port;
 
-    if (pack_nodes(plain_message, sizeof(plain_message), &receiver, 1) == -1) {
+    if (pack_nodes(dht->log, plain_message, sizeof(plain_message), &receiver, 1) == -1) {
         return false;
     }
 
@@ -1334,6 +1338,7 @@ bool dht_getnodes(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key, c
     ping_id = ping_array_add(dht->dht_ping_array, dht->mono_time, plain_message, sizeof(receiver));
 
     if (ping_id == 0) {
+        LOGGER_ERROR(dht->log, "adding ping id failed");
         return false;
     }
 
@@ -1352,6 +1357,7 @@ bool dht_getnodes(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key, c
     crypto_memzero(shared_key, sizeof(shared_key));
 
     if (len != sizeof(data)) {
+        LOGGER_ERROR(dht->log, "getnodes packet encryption failed");
         return false;
     }
 
@@ -1383,7 +1389,7 @@ static int sendnodes_ipv6(const DHT *dht, const IP_Port *ip_port, const uint8_t
     int nodes_length = 0;
 
     if (num_nodes > 0) {
-        nodes_length = pack_nodes(plain + 1, node_format_size * MAX_SENT_NODES, nodes_list, num_nodes);
+        nodes_length = pack_nodes(dht->log, plain + 1, node_format_size * MAX_SENT_NODES, nodes_list, num_nodes);
 
         if (nodes_length <= 0) {
             return -1;
@@ -1841,9 +1847,14 @@ static void do_Close(DHT *dht)
     }
 }
 
-void dht_bootstrap(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key)
+bool dht_bootstrap(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key)
 {
-    dht_getnodes(dht, ip_port, public_key, dht->self_public_key);
+    if (id_equal(public_key, dht->self_public_key)) {
+        // Bootstrapping off ourselves is ok (onion paths are still set up).
+        return true;
+    }
+
+    return dht_getnodes(dht, ip_port, public_key, dht->self_public_key);
 }
 
 int dht_bootstrap_from_address(DHT *dht, const char *address, bool ipv6enabled,
@@ -2682,8 +2693,7 @@ void dht_save(const DHT *dht, uint8_t *data)
         }
     }
 
-    state_write_section_header(old_data, DHT_STATE_COOKIE_TYPE, pack_nodes(data, sizeof(Node_format) * num, clients, num),
-                               DHT_STATE_TYPE_NODES);
+    state_write_section_header(old_data, DHT_STATE_COOKIE_TYPE, pack_nodes(dht->log, data, sizeof(Node_format) * num, clients, num), DHT_STATE_TYPE_NODES);
 
     free(clients);
 }

toxcore/DHT.h

@@ -148,7 +148,7 @@ int packed_node_size(Family ip_family);
  * Return -1 on failure.
  */
 non_null()
-int pack_ip_port(uint8_t *data, uint16_t length, const IP_Port *ip_port);
+int pack_ip_port(const Logger *logger, uint8_t *data, uint16_t length, const IP_Port *ip_port);
 
 /** Unpack IP_Port structure from data of max size length into ip_port.
  *
@@ -166,7 +166,7 @@ int unpack_ip_port(IP_Port *ip_port, const uint8_t *data, uint16_t length, bool
  * return -1 on failure.
  */
 non_null()
-int pack_nodes(uint8_t *data, uint16_t length, const Node_format *nodes, uint16_t number);
+int pack_nodes(const Logger *logger, uint8_t *data, uint16_t length, const Node_format *nodes, uint16_t number);
 
 /** Unpack data of length into nodes of size max_num_nodes.
  * Put the length of the data processed in processed_data_len.
@@ -359,7 +359,7 @@ void do_dht(DHT *dht);
  *   to setup connections
  */
 non_null()
-void dht_bootstrap(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key);
+bool dht_bootstrap(DHT *dht, const IP_Port *ip_port, const uint8_t *public_key);
 
 /** Resolves address into an IP address. If successful, sends a "get nodes"
  *   request to the given node with ip, port and public_key to setup connections

toxcore/Messenger.c

@@ -533,8 +533,6 @@ int m_send_message_generic(Messenger *m, int32_t friendnumber, uint8_t type, con
                                            m->friendlist[friendnumber].friendcon_id), packet, length + 1, false);
 
     if (packet_num == -1) {
-        LOGGER_WARNING(m->log, "failed to write crypto packet for message of length %d to friend %d",
-                       length, friendnumber);
         return -4;
     }
 
@@ -3008,7 +3006,7 @@ static uint8_t *save_tcp_relays(const Messenger *m, uint8_t *data)
     uint32_t num = m->num_loaded_relays;
     num += copy_connected_tcp_relays(m->net_crypto, relays + num, NUM_SAVED_TCP_RELAYS - num);
 
-    const int l = pack_nodes(data, NUM_SAVED_TCP_RELAYS * packed_node_size(net_family_tcp_ipv6), relays, num);
+    const int l = pack_nodes(m->log, data, NUM_SAVED_TCP_RELAYS * packed_node_size(net_family_tcp_ipv6), relays, num);
 
     if (l > 0) {
         const uint32_t len = l;
@@ -3052,7 +3050,7 @@ static uint8_t *save_path_nodes(const Messenger *m, uint8_t *data)
     data = state_write_section_header(data, STATE_COOKIE_TYPE, 0, STATE_TYPE_PATH_NODE);
     memset(nodes, 0, sizeof(nodes));
     const unsigned int num = onion_backup_nodes(m->onion_c, nodes, NUM_SAVED_PATH_NODES);
-    const int l = pack_nodes(data, NUM_SAVED_PATH_NODES * packed_node_size(net_family_tcp_ipv6), nodes, num);
+    const int l = pack_nodes(m->log, data, NUM_SAVED_PATH_NODES * packed_node_size(net_family_tcp_ipv6), nodes, num);
 
     if (l > 0) {
         const uint32_t len = l;

toxcore/friend_connection.c

@@ -298,7 +298,7 @@ static unsigned int send_relays(Friend_Connections *fr_c, int friendcon_id)
         friend_add_tcp_relay(fr_c, friendcon_id, &nodes[i].ip_port, nodes[i].public_key);
     }
 
-    int length = pack_nodes(data + 1, sizeof(data) - 1, nodes, n);
+    int length = pack_nodes(fr_c->logger, data + 1, sizeof(data) - 1, nodes, n);
 
     if (length <= 0) {
         return 0;

toxcore/network.c

@@ -558,6 +558,12 @@ int send_packet(const Networking_Core *net, const IP_Port *ip_port, Packet packe
 {
     IP_Port ipp_copy = *ip_port;
 
+    if (net_family_is_unspec(ip_port->ip.family)) {
+        // TODO(iphydf): Make this an error. Currently this fails sometimes when
+        // called from DHT.c:do_ping_and_sendnode_requests.
+        return -1;
+    }
+
     if (net_family_is_unspec(net->family)) { /* Socket not initialized */
         // TODO(iphydf): Make this an error. Currently, the onion client calls
         // this via DHT getnodes.
@@ -611,9 +617,7 @@ int send_packet(const Networking_Core *net, const IP_Port *ip_port, Packet packe
         addr6->sin6_flowinfo = 0;
         addr6->sin6_scope_id = 0;
     } else {
-        // TODO(iphydf): Make this an error. Currently this fails sometimes when
-        // called from DHT.c:do_ping_and_sendnode_requests.
-        LOGGER_WARNING(net->log, "unknown address type: %d", ipp_copy.ip.family.value);
+        LOGGER_ERROR(net->log, "unknown address type: %d", ipp_copy.ip.family.value);
         return -1;
     }
 
@@ -743,7 +747,9 @@ void networking_poll(const Networking_Core *net, void *userdata)
         const Packet_Handler *const handler = &net->packethandlers[data[0]];
 
         if (handler->function == nullptr) {
-            LOGGER_WARNING(net->log, "[%02u] -- Packet has no handler", data[0]);
+            // TODO(https://github.com/TokTok/c-toxcore/issues/1115): Make this
+            // a warning or error again.
+            LOGGER_DEBUG(net->log, "[%02u] -- Packet has no handler", data[0]);
             continue;
         }
 
@@ -962,8 +968,11 @@ Networking_Core *new_networking_ex(const Logger *log, const IP *ip, uint16_t por
 
     if (net_family_is_ipv6(ip->family)) {
         const bool is_dualstack = set_socket_dualstack(temp->sock);
-        LOGGER_DEBUG(log, "Dual-stack socket: %s",
-                     is_dualstack ? "enabled" : "Failed to enable, won't be able to receive from/send to IPv4 addresses");
+        if (is_dualstack) {
+            LOGGER_TRACE(log, "Dual-stack socket: enabled");
+        } else {
+            LOGGER_ERROR(log, "Dual-stack socket failed to enable, won't be able to receive from/send to IPv4 addresses");
+        }
         /* multicast local nodes */
         struct ipv6_mreq mreq;
         memset(&mreq, 0, sizeof(mreq));
@@ -978,9 +987,9 @@ Networking_Core *new_networking_ex(const Logger *log, const IP *ip, uint16_t por
         char *strerror = net_new_strerror(neterror);
 
         if (res < 0) {
-            LOGGER_DEBUG(log, "Failed to activate local multicast membership. (%d, %s)", neterror, strerror);
+            LOGGER_INFO(log, "Failed to activate local multicast membership in FF02::1. (%d, %s)", neterror, strerror);
         } else {
-            LOGGER_DEBUG(log, "Local multicast group FF02::1 joined successfully. (%d, %s)", neterror, strerror);
+            LOGGER_TRACE(log, "Local multicast group joined successfully. (%d, %s)", neterror, strerror);
         }
 
         net_kill_strerror(strerror);

toxcore/onion_announce.c

@@ -445,7 +445,7 @@ static int handle_announce_request(void *object, const IP_Port *source, const ui
     int nodes_length = 0;
 
     if (num_nodes != 0) {
-        nodes_length = pack_nodes(pl + 1 + ONION_PING_ID_SIZE, sizeof(nodes_list), nodes_list, num_nodes);
+        nodes_length = pack_nodes(onion_a->log, pl + 1 + ONION_PING_ID_SIZE, sizeof(nodes_list), nodes_list, num_nodes);
 
         if (nodes_length <= 0) {
             return 1;