more consistent error messages from RADIUS.

diff --git a/src/listen/radius/proto_radius.c b/src/listen/radius/proto_radius.c
index 5b1fc4175b0ab4fe274363c48076eeb906b1b2a5..4734398ceab0a661b3fe74b66b3dac0abe2713a4 100644 (file)
--- a/src/listen/radius/proto_radius.c
+++ b/src/listen/radius/proto_radius.c
@@ -191,6 +191,39 @@ static int transport_parse(TALLOC_CTX *ctx, void *out, void *parent, CONF_ITEM *
        return 0;
 }
 
+DIAG_OFF(format-nonliteral)
+/** Log a message in a canonical format.
+ *
+ *  'fmt' is from our source code, so we don't care about format literals.
+ */
+void proto_radius_log(fr_listen_t *li, char const *name, fr_radius_decode_fail_t reason,
+                     fr_socket_t const *sock, char const *fmt, ...)
+{
+       va_list ap;
+       char *msg = NULL;
+
+       if (!DEBUG_ENABLED2) return;
+
+       va_start(ap, fmt);
+       if (*fmt) msg = talloc_asprintf(NULL, fmt, ap);
+       va_end(ap);
+
+       DEBUG2("proto_%s - failed reading socket %s - %s",
+              li->app_io->common.name, name, fr_radius_decode_fail_reason[reason]);
+
+       if (sock) {
+               DEBUG2("proto_%s - from client %pV port %u",
+                      li->app_io->common.name, fr_box_ipaddr(sock->inet.src_ipaddr), sock->inet.src_port);
+       }
+
+       if (!msg) return;
+
+       DEBUG2("proto_%s - %s",
+              li->app_io->common.name, name, msg);
+       talloc_free(msg);
+}
+DIAG_ON(format-nonliteral)
+
 /** Decode the packet
  *
  */

diff --git a/src/listen/radius/proto_radius.h b/src/listen/radius/proto_radius.h
index 865e8eba02cd792875de11700b4914a2f67c99ef..e64193a83c49754e3008dabc07e8f5fb20b35ed3 100644 (file)
--- a/src/listen/radius/proto_radius.h
+++ b/src/listen/radius/proto_radius.h
@@ -45,3 +45,5 @@ typedef struct {
        fr_radius_limit_proxy_state_t   limit_proxy_state;              //!< Limit Proxy-State to packets containing
                                                                        ///< Message-Authenticator.
 } proto_radius_t;
+
+void proto_radius_log(fr_listen_t *li, char const *name, fr_radius_decode_fail_t reason, fr_socket_t const *sock, char const *fmt, ...);

diff --git a/src/listen/radius/proto_radius_tcp.c b/src/listen/radius/proto_radius_tcp.c
index a11ae376da1bba7fb065af4280c032ef84eab1a7..dde4b1bc8442c03d4c2b4deac2b1219ae4bde46b 100644 (file)
--- a/src/listen/radius/proto_radius_tcp.c
+++ b/src/listen/radius/proto_radius_tcp.c
@@ -152,7 +152,8 @@ static ssize_t mod_read(fr_listen_t *li, UNUSED void **packet_ctx, fr_time_t *re
                        break;
                }
 
-               PDEBUG2("proto_radius_tcp got read error (%zd) - %s", data_size, fr_syserror(errno));
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_IO_ERROR, NULL,
+                                "error reading socket - %s", fr_strerror());
                return data_size;
        }
 
@@ -166,7 +167,8 @@ static ssize_t mod_read(fr_listen_t *li, UNUSED void **packet_ctx, fr_time_t *re
         *      TCP read of zero means the socket is dead.
         */
        if (!data_size) {
-               DEBUG2("proto_radius_tcp - other side closed the socket.");
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_IO_ERROR, NULL,
+                                "Client closed the connection");
                return -1;
        }
 
@@ -175,7 +177,8 @@ have_packet:
         *      We MUST always start with a known RADIUS packet.
         */
        if ((buffer[0] == 0) || (buffer[0] >= FR_RADIUS_CODE_MAX)) {
-               DEBUG("proto_radius_tcp got invalid packet code %d", buffer[0]);
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_UNKNOWN_PACKET_CODE, NULL,
+                                "received packet code %u", buffer[0]);
                thread->stats.total_unknown_types++;
                return -1;
        }
@@ -214,10 +217,7 @@ have_packet:
         *      If it's not a RADIUS packet, ignore it.
         */
        if (!fr_radius_ok(buffer, &packet_len, inst->max_attributes, false, &reason)) {
-               /*
-                *      @todo - check for F5 load balancer packets.  <sigh>
-                */
-               DEBUG2("proto_radius_tcp got a packet which isn't RADIUS");
+               proto_radius_log(li, thread->name, reason, NULL, "");
                thread->stats.total_malformed_requests++;
                return -1;
        }

diff --git a/src/listen/radius/proto_radius_tcp.mk b/src/listen/radius/proto_radius_tcp.mk
index 6c84f850c1a11fc21dfae9d2a00d992da2eac351..43935010902c1c48523ae1c42bd32f0b903dbac9 100644 (file)
--- a/src/listen/radius/proto_radius_tcp.mk
+++ b/src/listen/radius/proto_radius_tcp.mk
@@ -6,4 +6,4 @@ endif
 
 SOURCES                := proto_radius_tcp.c
 
-TGT_PREREQS    := libfreeradius-radius$(L)
+TGT_PREREQS    := libfreeradius-radius$(L) proto_radius$(L)

diff --git a/src/listen/radius/proto_radius_udp.c b/src/listen/radius/proto_radius_udp.c
index f543323fa4cbb0cc6a9133ea2c6178348b6ea8b8..6ff60158f371ac4056b02cf4e9237ae52e7b7edd 100644 (file)
--- a/src/listen/radius/proto_radius_udp.c
+++ b/src/listen/radius/proto_radius_udp.c
@@ -144,43 +144,46 @@ static ssize_t mod_read(fr_listen_t *li, void **packet_ctx, fr_time_t *recv_time
 
        data_size = udp_recv(thread->sockfd, flags, &address->socket, buffer, buffer_len, recv_time_p);
        if (data_size < 0) {
-               PDEBUG2("proto_radius_udp got read error");
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_IO_ERROR, NULL,
+                                "error reading socket - %s", fr_strerror());
                return data_size;
        }
 
        if (!data_size) {
-               DEBUG2("proto_radius_udp got no data: ignoring");
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_IO_ERROR, NULL,
+                                "no data received");
                return 0;
        }
 
        packet_len = data_size;
 
        if (data_size < 20) {
-               DEBUG2("proto_radius_udp got 'too short' packet size %zd", data_size);
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_MIN_LENGTH_PACKET, &address->socket,
+                                "received %zu which is smaller than minimum 20", packet_len);
                thread->stats.total_malformed_requests++;
                return 0;
        }
 
        if (packet_len > inst->max_packet_size) {
-               DEBUG2("proto_radius_udp got 'too long' packet size %zd > %u", data_size, inst->max_packet_size);
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_MIN_LENGTH_PACKET, &address->socket,
+                                "received %zu which is larger than maximum %zu", packet_len, inst->max_packet_size);
                thread->stats.total_malformed_requests++;
                return 0;
        }
 
-       if ((buffer[0] == 0) || (buffer[0] > FR_RADIUS_CODE_MAX)) {
-               DEBUG("proto_radius_udp got invalid packet code %d", buffer[0]);
+       if ((buffer[0] == 0) || (buffer[0] >= FR_RADIUS_CODE_MAX)) {
+               proto_radius_log(li, thread->name, FR_RADIUS_FAIL_UNKNOWN_PACKET_CODE, &address->socket,
+                                "received packet code %u", buffer[0]);
                thread->stats.total_unknown_types++;
                return 0;
        }
 
        /*
-        *      If it's not a RADIUS packet, ignore it.
+        *      If it's not well-formed, discard it.
         */
        if (!fr_radius_ok(buffer, &packet_len, inst->max_attributes, false, &reason)) {
-               /*
-                *      @todo - check for F5 load balancer packets.  <sigh>
-                */
-               DEBUG2("proto_radius_udp got a packet which isn't RADIUS: %s", fr_strerror());
+               proto_radius_log(li, thread->name, reason, &address->socket,
+                                "");
                thread->stats.total_malformed_requests++;
                return 0;
        }

diff --git a/src/listen/radius/proto_radius_udp.mk b/src/listen/radius/proto_radius_udp.mk
index a39cca9689041df03122ea05ba6be76a080c1310..873828c374ee0ea3959a3ac7e36b687079bdada2 100644 (file)
--- a/src/listen/radius/proto_radius_udp.mk
+++ b/src/listen/radius/proto_radius_udp.mk
@@ -6,4 +6,4 @@ endif
 
 SOURCES                := proto_radius_udp.c
 
-TGT_PREREQS    := libfreeradius-radius$(L)
+TGT_PREREQS    := libfreeradius-radius$(L) proto_radius$(L)

diff --git a/src/protocols/radius/base.c b/src/protocols/radius/base.c
index 01b878a788a4095d296e03adf979f7ea33f4b322..8c97a96be8fe5aa0a85c73d5c7005d929931a8b9 100644 (file)
--- a/src/protocols/radius/base.c
+++ b/src/protocols/radius/base.c
@@ -530,6 +530,7 @@ char const *fr_radius_decode_fail_reason[FR_RADIUS_FAIL_MAX + 1] = {
 
        [FR_RADIUS_FAIL_VERIFY] = "packet fails verification (shared secret is incorrect)",
        [FR_RADIUS_FAIL_NO_MATCHING_REQUEST] = "did not find request which matched response",
+       [FR_RADIUS_FAIL_IO_ERROR] = "IO error",
        [FR_RADIUS_FAIL_MAX] = "???",
 };
 

diff --git a/src/protocols/radius/radius.h b/src/protocols/radius/radius.h
index d0fc62e72eeddfacbbf443d0d1914b1db14cb506..2e2cd5238896021160bc832dcf652830d2a912e5 100644 (file)
--- a/src/protocols/radius/radius.h
+++ b/src/protocols/radius/radius.h
@@ -112,6 +112,7 @@ typedef enum {
 
        FR_RADIUS_FAIL_VERIFY,
        FR_RADIUS_FAIL_NO_MATCHING_REQUEST,
+       FR_RADIUS_FAIL_IO_ERROR,
        FR_RADIUS_FAIL_MAX
 } fr_radius_decode_fail_t;