Add debug messages to RTR interactions

Requested by tester.

diff --git a/src/address.c b/src/address.c
index 93e62e4d44769ce760dbe6721a913365a425ff82..3276469631b7faff5764d249da1f766b4a620c37 100644 (file)
--- a/src/address.c
+++ b/src/address.c
@@ -525,3 +525,32 @@ ipv6_covered(struct in6_addr *f_addr, uint8_t f_len, struct in6_addr *son_addr)
 
        return true;
 }
+
+/**
+ * buffer must length INET6_ADDRSTRLEN.
+ */
+char const *
+sockaddr2str(struct sockaddr_storage *sockaddr, char *buffer)
+{
+       void *addr = NULL;
+       char const *addr_str;
+
+       if (sockaddr == NULL)
+               return "(null)";
+
+       switch (sockaddr->ss_family) {
+       case AF_INET:
+               addr = &((struct sockaddr_in *) sockaddr)->sin_addr;
+               break;
+       case AF_INET6:
+               addr = &((struct sockaddr_in6 *) sockaddr)->sin6_addr;
+               break;
+       default:
+               return "(protocol unknown)";
+       }
+
+       addr_str = inet_ntop(sockaddr->ss_family, addr, buffer,
+           INET6_ADDRSTRLEN);
+       return (addr_str != NULL) ? addr_str : "(unprintable address)";
+}
+

diff --git a/src/address.h b/src/address.h
index fb6e1e7a2dc536713dac377eea39be65fbe2ae18..11670bf94d1ff3745240703c215f12e7d86a648b 100644 (file)
--- a/src/address.h
+++ b/src/address.h
@@ -3,6 +3,7 @@
 
 #include <stdbool.h>
 #include <netinet/in.h>
+#include <sys/socket.h>
 #include "asn1/asn1c/IPAddress.h"
 #include "asn1/asn1c/IPAddressRange.h"
 
@@ -50,4 +51,6 @@ int ipv6_prefix_validate(struct ipv6_prefix *);
 bool ipv4_covered(struct in_addr *, uint8_t, struct in_addr *);
 bool ipv6_covered(struct in6_addr *, uint8_t, struct in6_addr *);
 
+char const *sockaddr2str(struct sockaddr_storage *, char *);
+
 #endif /* SRC_ADDRESS_H_ */

diff --git a/src/rtr/pdu.c b/src/rtr/pdu.c
index 4350d24e0005bc9207b556fd206e0791e614c414..d69db34fe0355b5029790ae9def8fefefa1b163a 100644 (file)
--- a/src/rtr/pdu.c
+++ b/src/rtr/pdu.c
@@ -4,12 +4,42 @@
 #include <stdlib.h>
 #include <string.h>
 
+#include "address.h"
 #include "clients.h"
 #include "common.h"
 #include "log.h"
 #include "rtr/err_pdu.h"
 #include "rtr/pdu_handler.h"
 
+char const *
+pdutype2str(enum pdu_type type)
+{
+       switch (type) {
+       case PDU_TYPE_SERIAL_NOTIFY:
+               return "Serial Notify";
+       case PDU_TYPE_SERIAL_QUERY:
+               return "Serial Query";
+       case PDU_TYPE_RESET_QUERY:
+               return "Reset Query";
+       case PDU_TYPE_CACHE_RESPONSE:
+               return "Cache Response";
+       case PDU_TYPE_IPV4_PREFIX:
+               return "IPv4 Prefix";
+       case PDU_TYPE_IPV6_PREFIX:
+               return "IPv6 Prefix";
+       case PDU_TYPE_END_OF_DATA:
+               return "End of Data";
+       case PDU_TYPE_CACHE_RESET:
+               return "Cache Reset";
+       case PDU_TYPE_ROUTER_KEY:
+               return "Router Key";
+       case PDU_TYPE_ERROR_REPORT:
+               return "Error Report";
+       }
+
+       return "(unknown)";
+}
+
 static int
 pdu_header_from_reader(struct pdu_reader *reader, struct pdu_header *header)
 {
@@ -75,8 +105,8 @@ validate_rtr_version(int fd, struct pdu_header *header,
 }
 
 int
-pdu_load(int fd, struct rtr_request *request,
-    struct pdu_metadata const **metadata)
+pdu_load(int fd, struct sockaddr_storage *client_addr,
+    struct rtr_request *request, struct pdu_metadata const **metadata)
 {
        unsigned char hdr_bytes[RTRPDU_HDR_LEN];
        struct pdu_reader reader;
@@ -95,6 +125,15 @@ pdu_load(int fd, struct rtr_request *request,
                /* No error response because the PDU might have been an error */
                return error;
 
+#ifdef DEBUG
+       {
+               char buffer[INET6_ADDRSTRLEN];
+               pr_debug("Received a %s PDU from %s.",
+                   pdutype2str(header.pdu_type),
+                   sockaddr2str(client_addr, buffer));
+       }
+#endif
+
        error = validate_rtr_version(fd, &header, hdr_bytes);
        if (error)
                return error; /* Error response PDU already sent */
@@ -105,7 +144,10 @@ pdu_load(int fd, struct rtr_request *request,
        /*
         * DO NOT USE THE err_pdu_* functions directly. Wrap them with
         * RESPOND_ERROR() INSTEAD.
+        * TODO I think this comment should be above validate_rtr_version(),
+        * and validate_rtr_version() is buggy.
         */
+
        if (header.length < RTRPDU_HDR_LEN)
                return RESPOND_ERROR(err_pdu_send_invalid_request_truncated(fd,
                    version, hdr_bytes, "Invalid header length. (< 8 bytes)"));

diff --git a/src/rtr/pdu.h b/src/rtr/pdu.h
index db752c17aa260107c2afefb836ceb885fd314a7a..5afdfcb8f8b108fabb94b52ad88e536235b29097 100644 (file)
--- a/src/rtr/pdu.h
+++ b/src/rtr/pdu.h
@@ -34,6 +34,8 @@ enum pdu_type {
        PDU_TYPE_ERROR_REPORT =         10,
 };
 
+char const *pdutype2str(enum pdu_type);
+
 /*
  * Note: It's probably best not to use sizeof for these lengths, because it
  * risks including padding, and this is not the place for it.
@@ -155,7 +157,8 @@ struct pdu_metadata {
        void    (*destructor)(void *);
 };
 
-int pdu_load(int, struct rtr_request *, struct pdu_metadata const **);
+int pdu_load(int, struct sockaddr_storage *, struct rtr_request *,
+    struct pdu_metadata const **);
 struct pdu_metadata const *pdu_get_metadata(uint8_t);
 struct pdu_header *pdu_get_header(void *);
 

diff --git a/src/rtr/pdu_sender.c b/src/rtr/pdu_sender.c
index b1b5bfdd0b10b45d2838259ec9d929eb51fa8901..9fca99da00f6b2bd6faf73cd7e220b6405d6f440 100644 (file)
--- a/src/rtr/pdu_sender.c
+++ b/src/rtr/pdu_sender.c
@@ -5,6 +5,9 @@
 #include <stdlib.h>
 #include <string.h>
 #include <unistd.h>
+#include <arpa/inet.h> /* inet_ntop */
+#include <sys/types.h> /* AF_INET, AF_INET6 (needed in OpenBSD) */
+#include <sys/socket.h> /* AF_INET, AF_INET6 (needed in OpenBSD) */
 
 #include "clients.h"
 #include "config.h"
@@ -25,10 +28,12 @@ set_header_values(struct pdu_header *header, uint8_t version, uint8_t type,
 }
 
 static int
-send_response(int fd, unsigned char *data, size_t data_len)
+send_response(int fd, uint8_t pdu_type, unsigned char *data, size_t data_len)
 {
        int error;
 
+       pr_debug("Sending %s PDU to client.", pdutype2str(pdu_type));
+
        error = write(fd, data, data_len);
        if (error < 0)
                return pr_errno(errno, "Error sending response");
@@ -53,7 +58,7 @@ send_serial_notify_pdu(int fd, uint8_t version, serial_t start_serial)
        if (len != RTRPDU_SERIAL_NOTIFY_LEN)
                pr_crit("Serialized Serial Notify is %zu bytes.", len);
 
-       return send_response(fd, data, len);
+       return send_response(fd, pdu.header.pdu_type, data, len);
 }
 
 int
@@ -71,7 +76,7 @@ send_cache_reset_pdu(int fd, uint8_t version)
        if (len != RTRPDU_CACHE_RESET_LEN)
                pr_crit("Serialized Cache Reset is %zu bytes.", len);
 
-       return send_response(fd, data, len);
+       return send_response(fd, pdu.header.pdu_type, data, len);
 }
 
 int
@@ -90,7 +95,22 @@ send_cache_response_pdu(int fd, uint8_t version)
        if (len != RTRPDU_CACHE_RESPONSE_LEN)
                pr_crit("Serialized Cache Response is %zu bytes.", len);
 
-       return send_response(fd, data, len);
+       return send_response(fd, pdu.header.pdu_type, data, len);
+}
+
+static void
+pr_debug_prefix4(struct ipv4_prefix_pdu *pdu)
+{
+#ifdef DEBUG
+       char buffer[INET_ADDRSTRLEN];
+       char const *addr_str;
+
+       addr_str = inet_ntop(AF_INET, &pdu->ipv4_prefix, buffer,
+           INET_ADDRSTRLEN);
+
+       pr_debug("Encoded prefix %s/%u into a PDU.", addr_str,
+           pdu->prefix_length);
+#endif
 }
 
 static int
@@ -114,8 +134,24 @@ send_ipv4_prefix_pdu(int fd, uint8_t version, struct vrp const *vrp,
        len = serialize_ipv4_prefix_pdu(&pdu, data);
        if (len != RTRPDU_IPV4_PREFIX_LEN)
                pr_crit("Serialized IPv4 Prefix is %zu bytes.", len);
+       pr_debug_prefix4(&pdu);
+
+       return send_response(fd, pdu.header.pdu_type, data, len);
+}
+
+static void
+pr_debug_prefix6(struct ipv6_prefix_pdu *pdu)
+{
+#ifdef DEBUG
+       char buffer[INET6_ADDRSTRLEN];
+       char const *addr_str;
+
+       addr_str = inet_ntop(AF_INET6, &pdu->ipv6_prefix, buffer,
+           INET6_ADDRSTRLEN);
 
-       return send_response(fd, data, len);
+       pr_debug("Encoded prefix %s/%u into a PDU.", addr_str,
+           pdu->prefix_length);
+#endif
 }
 
 static int
@@ -139,8 +175,9 @@ send_ipv6_prefix_pdu(int fd, uint8_t version, struct vrp const *vrp,
        len = serialize_ipv6_prefix_pdu(&pdu, data);
        if (len != RTRPDU_IPV6_PREFIX_LEN)
                pr_crit("Serialized IPv6 Prefix is %zu bytes.", len);
+       pr_debug_prefix6(&pdu);
 
-       return send_response(fd, data, len);
+       return send_response(fd, pdu.header.pdu_type, data, len);
 }
 
 int
@@ -186,7 +223,7 @@ send_router_key_pdu(int fd, uint8_t version,
                pr_crit("Serialized Router Key PDU is %zu bytes, not the expected %u.",
                    len, pdu.header.length);
 
-       return send_response(fd, data, len);
+       return send_response(fd, pdu.header.pdu_type, data, len);
 }
 
 struct simple_param {
@@ -262,7 +299,7 @@ send_end_of_data_pdu(int fd, uint8_t version, serial_t end_serial)
        if (len != GET_END_OF_DATA_LENGTH(version))
                pr_crit("Serialized End of Data is %zu bytes.", len);
 
-       error = send_response(fd, data, len);
+       error = send_response(fd, pdu.header.pdu_type, data, len);
        if (error)
                return error;
 
@@ -308,7 +345,7 @@ send_error_report_pdu(int fd, uint8_t version, uint16_t code,
                pr_crit("Serialized Error Report PDU is %zu bytes, not the expected %u.",
                    len, pdu.header.length);
 
-       error = send_response(fd, data, len);
+       error = send_response(fd, pdu.header.pdu_type, data, len);
 
        free(data);
        return error;

diff --git a/src/rtr/rtr.c b/src/rtr/rtr.c
index 1345ece63ef97f369a365857ecdf85fbc75f861b..7b285bb52c70d3800b722bc9b88b8d43593c7507 100644 (file)
--- a/src/rtr/rtr.c
+++ b/src/rtr/rtr.c
@@ -76,7 +76,6 @@ init_addrinfo(struct addrinfo **result)
        return 0;
 }
 
-
 /*
  * Creates the socket that will stay put and wait for new connections started
  * from the clients.
@@ -203,31 +202,12 @@ print_close_failure(int error, int fd)
 {
        struct sockaddr_storage sockaddr;
        char buffer[INET6_ADDRSTRLEN];
-       void *addr = NULL;
        char const *addr_str;
 
-       if (clients_get_addr(fd, &sockaddr) != 0) {
-               addr_str = "(unknown)";
-               goto done;
-       }
-       switch (sockaddr.ss_family) {
-       case AF_INET:
-               addr = &((struct sockaddr_in *) &sockaddr)->sin_addr;
-               break;
-       case AF_INET6:
-               addr = &((struct sockaddr_in6 *) &sockaddr)->sin6_addr;
-               break;
-       default:
-               addr_str = "(protocol unknown)";
-               goto done;
-       }
-
-       addr_str = inet_ntop(sockaddr.ss_family, addr, buffer,
-           INET6_ADDRSTRLEN);
-       if (addr_str == NULL)
-               addr_str = "(unprintable address)";
+       addr_str = (clients_get_addr(fd, &sockaddr) == 0)
+           ? sockaddr2str(&sockaddr, buffer)
+           : "(unknown)";
 
-done:
        pr_errno(error, "close() failed on socket of client %s", addr_str);
 }
 
@@ -258,8 +238,9 @@ client_thread_cb(void *arg)
                close(param.fd);
                return NULL;
        }
+
        while (true) { /* For each PDU... */
-               error = pdu_load(param.fd, &request, &meta);
+               error = pdu_load(param.fd, &param.addr, &request, &meta);
                if (error)
                        break;
 
@@ -294,6 +275,7 @@ handle_client_connections(int server_fd)
 
        sizeof_client_addr = sizeof(client_addr);
 
+       pr_debug("Waiting for client connections...");
        do {
                client_fd = accept(server_fd, (struct sockaddr *) &client_addr,
                    &sizeof_client_addr);
@@ -306,6 +288,14 @@ handle_client_connections(int server_fd)
                        return -EINVAL;
                }
 
+#ifdef DEBUG
+               {
+                       char buffer[INET6_ADDRSTRLEN];
+                       pr_debug("Client accepted: %s",
+                           sockaddr2str(&client_addr, buffer));
+               }
+#endif
+
                /*
                 * Note: My gut says that errors from now on (even the unknown
                 * ones) should be treated as temporary; maybe the next

diff --git a/test/impersonator.c b/test/impersonator.c
index 16a9140d10b6e61f5fae5510ab7aaa25b914bcde..b790bd399989c1335aac787787b6bb100010ec30 100644 (file)
--- a/test/impersonator.c
+++ b/test/impersonator.c
@@ -34,6 +34,12 @@ v6addr2str2(struct in6_addr const *addr)
        return inet_ntop(AF_INET6, addr, addr_buffer2, sizeof(addr_buffer2));
 }
 
+char const *
+fnstack_peek(void)
+{
+       return NULL;
+}
+
 char const *
 config_get_tal(void)
 {

diff --git a/test/rtr/pdu_handler_test.c b/test/rtr/pdu_handler_test.c
index c164af11c27d790b132df7eba7cbd0da3214c1e8..ab338e70352fd3d6a2109d1cbd2253aa5d18b7f7 100644 (file)
--- a/test/rtr/pdu_handler_test.c
+++ b/test/rtr/pdu_handler_test.c
@@ -447,7 +447,7 @@ START_TEST(test_bad_length)
        expected_pdu_add(PDU_TYPE_ERROR_REPORT);
 
        /* Run and validate, before handling */
-       ck_assert_int_eq(-EINVAL, pdu_load(fd, &request, &meta));
+       ck_assert_int_eq(-EINVAL, pdu_load(fd, NULL, &request, &meta));
        ck_assert_uint_eq(false, has_expected_pdus());
 
        /* Clean up */