Remove the debug_pair calls from the protocol encoders/decoders

Fixes the double packet debug output

diff --git a/src/include/radiusd.h b/src/include/radiusd.h
index 2aca316..4754e6d 100644 (file)
--- a/src/include/radiusd.h
+++ b/src/include/radiusd.h
@@ -533,6 +533,7 @@ int         session_zap(REQUEST *request, uint32_t nasaddr,
 void           debug_pair(VALUE_PAIR *);
 void           rdebug_pair(int level, REQUEST *, VALUE_PAIR *);
 void           rdebug_pair_list(int level, REQUEST *, VALUE_PAIR *);
+void           rdebug_proto_pair_list(int level, REQUEST *, VALUE_PAIR *);
 int            log_err (char *);
 
 /* util.c */

diff --git a/src/lib/radius.c b/src/lib/radius.c
index 7875b55..7045dc8 100644 (file)
--- a/src/lib/radius.c
+++ b/src/lib/radius.c
@@ -824,8 +824,6 @@ static ssize_t vp2data_any(RADIUS_PACKET const *packet,
                                    start, room);
        }
 
-       debug_pair(vp);
-
        /*
         *      Set up the default sources for the data.
         */
@@ -1262,8 +1260,6 @@ static ssize_t vp2attr_concat(UNUSED RADIUS_PACKET const *packet,
 
        VERIFY_VP(vp);
 
-       debug_pair(vp);
-
        p = vp->vp_octets;
        len = vp->length;
 
@@ -1569,7 +1565,6 @@ int rad_vp2rfc(RADIUS_PACKET const *packet,
        if (vp->da->attr == PW_MESSAGE_AUTHENTICATOR) {
                if (room < 18) return -1;
 
-               debug_pair(vp);
                ptr[0] = PW_MESSAGE_AUTHENTICATOR;
                ptr[1] = 18;
                memset(ptr + 2, 0, 16);
@@ -1699,32 +1694,12 @@ int rad_encode(RADIUS_PACKET *packet, RADIUS_PACKET const *original,
        uint16_t                total_length;
        int                     len;
        VALUE_PAIR const        *reply;
-       char const              *what;
-       char                    ip_src_buffer[INET6_ADDRSTRLEN];
-       char                    ip_dst_buffer[INET6_ADDRSTRLEN];
 
        /*
         *      A 4K packet, aligned on 64-bits.
         */
        uint64_t        data[MAX_PACKET_LEN / sizeof(uint64_t)];
 
-       if (is_radius_code(packet->code)) {
-               what = fr_packet_codes[packet->code];
-       } else {
-               what = "Reply";
-       }
-
-       DEBUG("Sending %s Id %d from %s:%u to %s:%u\n",
-             what, packet->id,
-             inet_ntop(packet->src_ipaddr.af,
-                       &packet->src_ipaddr.ipaddr,
-                       ip_src_buffer, sizeof(ip_src_buffer)),
-             packet->src_port,
-             inet_ntop(packet->dst_ipaddr.af,
-                       &packet->dst_ipaddr.ipaddr,
-                       ip_dst_buffer, sizeof(ip_dst_buffer)),
-             packet->dst_port);
-
        /*
         *      Double-check some things based on packet code.
         */
@@ -2003,11 +1978,6 @@ int rad_sign(RADIUS_PACKET *packet, RADIUS_PACKET const *original,
 int rad_send(RADIUS_PACKET *packet, RADIUS_PACKET const *original,
             char const *secret)
 {
-       VALUE_PAIR              *reply;
-       char const              *what;
-       char                    ip_src_buffer[128];
-       char                    ip_dst_buffer[128];
-
        /*
         *      Maybe it's a fake packet.  Don't send it.
         */
@@ -2015,12 +1985,6 @@ int rad_send(RADIUS_PACKET *packet, RADIUS_PACKET const *original,
                return 0;
        }
 
-       if (is_radius_code(packet->code)) {
-               what = fr_packet_codes[packet->code];
-       } else {
-               what = "Reply";
-       }
-
        /*
         *  First time through, allocate room for the packet
         */
@@ -2044,21 +2008,6 @@ int rad_send(RADIUS_PACKET *packet, RADIUS_PACKET const *original,
                 *      If packet->data points to data, then we print out
                 *      the VP list again only for debugging.
                 */
-       } else if (fr_debug_flag) {
-               DEBUG("Sending %s Id %d from %s:%u to %s:%u\n", what,
-                     packet->id,
-                     inet_ntop(packet->src_ipaddr.af, &packet->src_ipaddr.ipaddr,
-                               ip_src_buffer, sizeof(ip_src_buffer)),
-                     packet->src_port,
-                     inet_ntop(packet->dst_ipaddr.af, &packet->dst_ipaddr.ipaddr,
-                               ip_dst_buffer, sizeof(ip_dst_buffer)),
-                     packet->dst_port);
-
-               for (reply = packet->vps; reply; reply = reply->next) {
-                       if ((reply->da->vendor == 0) &&
-                           ((reply->da->attr & 0xFFFF) > 0xff)) continue;
-                       debug_pair(reply);
-               }
        }
 
 #ifndef NDEBUG
@@ -2684,39 +2633,6 @@ RADIUS_PACKET *rad_recv(int fd, int flags)
         */
        packet->vps = NULL;
 
-       if (fr_debug_flag) {
-               char src_ipaddr[128];
-               char dst_ipaddr[128];
-
-               if (is_radius_code(packet->code)) {
-                       DEBUG("Received %s Id %d from %s:%d to %s:%d length %d\n",
-                             fr_packet_codes[packet->code],
-                             packet->id,
-                             inet_ntop(packet->src_ipaddr.af,
-                                       &packet->src_ipaddr.ipaddr,
-                                       src_ipaddr, sizeof(src_ipaddr)),
-                             packet->src_port,
-                             inet_ntop(packet->dst_ipaddr.af,
-                                       &packet->dst_ipaddr.ipaddr,
-                                       dst_ipaddr, sizeof(dst_ipaddr)),
-                             packet->dst_port,
-                             (int) packet->data_len);
-               } else {
-                       DEBUG("Received code %d Id %d from %s:%d to %s:%d length %d\n",
-                             packet->code,
-                             packet->id,
-                             inet_ntop(packet->src_ipaddr.af,
-                                       &packet->src_ipaddr.ipaddr,
-                                       src_ipaddr, sizeof(src_ipaddr)),
-                             packet->src_port,
-                             inet_ntop(packet->dst_ipaddr.af,
-                                       &packet->dst_ipaddr.ipaddr,
-                                       dst_ipaddr, sizeof(dst_ipaddr)),
-                             packet->dst_port,
-                             (int) packet->data_len);
-               }
-       }
-
 #ifndef NDEBUG
        if ((fr_debug_flag > 3) && fr_log_fp) rad_print_hex(packet);
 #endif
@@ -4086,7 +4002,6 @@ int rad_decode(RADIUS_PACKET *packet, RADIUS_PACKET *original,
                *tail = vp;
                while (vp) {
                        num_attributes++;
-                       debug_pair(vp);
                        tail = &(vp->next);
                        vp = vp->next;
                }

diff --git a/src/main/process.c b/src/main/process.c
index 92d70ec..04d442b 100644 (file)
--- a/src/main/process.c
+++ b/src/main/process.c
@@ -356,19 +356,13 @@ static void tv_add(struct timeval *tv, int usec_delay)
 /*
  *     Debug the packet if requested.
  */
-#define DEBUG_PACKET if (request->log.lvl && request->log.func) debug_packet
-
-static void debug_packet(REQUEST *request, RADIUS_PACKET *packet, int direction)
+static void debug_packet(REQUEST *request, RADIUS_PACKET *packet, bool received)
 {
-       vp_cursor_t cursor;
-       VALUE_PAIR *vp;
-       char buffer[1024];
        char src_ipaddr[128];
        char dst_ipaddr[128];
 
        if (!packet) return;
-
-       rad_assert(request->log.func != NULL);
+       if (!RDEBUG_ENABLED) return;
 
        /*
         *      Client-specific debugging re-prints the input
@@ -378,7 +372,7 @@ static void debug_packet(REQUEST *request, RADIUS_PACKET *packet, int direction)
         */
        if (is_radius_code(packet->code)) {
                RDEBUG("%s %s Id %i from %s:%i to %s:%i length %zu",
-                      direction == 0 ? "Received" : "Sending",
+                      received ? "Received" : "Sent",
                       fr_packet_codes[packet->code],
                       packet->id,
                       inet_ntop(packet->src_ipaddr.af,
@@ -392,7 +386,7 @@ static void debug_packet(REQUEST *request, RADIUS_PACKET *packet, int direction)
                       packet->data_len);
        } else {
                RDEBUG("%s code %i Id %i from %s:%i to %s:%i length %zu",
-                      direction == 0 ? "Received" : "Sending",
+                      received ? "Received" : "Sent",
                       packet->code,
                       packet->id,
                       inet_ntop(packet->src_ipaddr.af,
@@ -406,14 +400,11 @@ static void debug_packet(REQUEST *request, RADIUS_PACKET *packet, int direction)
                       packet->data_len);
        }
 
-       RINDENT();
-       for (vp = fr_cursor_init(&cursor, &packet->vps);
-            vp;
-            vp = fr_cursor_next(&cursor)) {
-               vp_prints(buffer, sizeof(buffer), vp);
-               RDEBUG("%s", buffer);
+       if (received) {
+               rdebug_pair_list(L_DBG_LVL_1, request, packet->vps);
+       } else {
+               rdebug_proto_pair_list(L_DBG_LVL_1, request, packet->vps);
        }
-       REXDENT();
 }
 
 
@@ -982,8 +973,8 @@ static void request_process_timer(REQUEST *request)
                } /* else it's time to send the reject */
 
                RDEBUG2("Sending delayed response");
-               DEBUG_PACKET(request, request->reply, 1);
                request->listener->send(request->listener, request);
+               debug_packet(request, request->reply, false);
                request->child_state = REQUEST_CLEANUP_DELAY;
                /* FALL-THROUGH */
 
@@ -1265,7 +1256,7 @@ static int CC_HINT(nonnull) request_pre_handler(REQUEST *request, UNUSED int act
                }
 #endif
 
-               DEBUG_PACKET(request, request->packet, 0);
+               debug_packet(request, request->packet, true);
        } else {
                rcode = 0;
        }
@@ -1407,16 +1398,14 @@ STATE_MACHINE_DECL(request_finish)
         */
        if (request->listener->type == RAD_LISTEN_DETAIL) {
        do_detail:
+               request->simul_max = 1;
+               request->listener->send(request->listener, request);
                /*
                 *      But only print the reply if there is one.
                 */
                if (request->reply->code != 0) {
-                       DEBUG_PACKET(request, request->reply, 1);
+                       debug_packet(request, request->reply, false);
                }
-
-               request->simul_max = 1;
-               request->listener->send(request->listener,
-                                       request);
                goto done;
        }
 #endif
@@ -1480,9 +1469,8 @@ STATE_MACHINE_DECL(request_finish)
                 *      Don't print a reply if there's none to send.
                 */
                if (request->reply->code != 0) {
-                       DEBUG_PACKET(request, request->reply, 1);
-                       request->listener->send(request->listener,
-                                               request);
+                       request->listener->send(request->listener, request);
+                       debug_packet(request, request->reply, false);
                }
        done:
                pairfree(&request->reply->vps);
@@ -2309,7 +2297,7 @@ static int process_proxy_reply(REQUEST *request, RADIUS_PACKET *reply)
                 */
                if (request->proxy_listener) {
                        rcode = request->proxy_listener->decode(request->proxy_listener, request);
-                       DEBUG_PACKET(request, reply, 0);
+                       debug_packet(request, reply, true);
 
                        /*
                         *      Pro-actively remove it from the proxy hash.
@@ -3011,7 +2999,7 @@ static int request_proxy(REQUEST *request, int retransmit)
                                request->proxy->dst_port,
                                (int) response_window->tv_sec, (int) response_window->tv_usec);
 
-               DEBUG_PACKET(request, request->proxy, 1);
+
        }
 
        gettimeofday(&request->proxy_retransmit, NULL);
@@ -3023,8 +3011,8 @@ static int request_proxy(REQUEST *request, int retransmit)
        FR_STATS_TYPE_INC(request->home_server->stats.total_requests);
        NO_CHILD_THREAD;
        request->child_state = REQUEST_PROXIED;
-       request->proxy_listener->send(request->proxy_listener,
-                                     request);
+       request->proxy_listener->send(request->proxy_listener, request);
+       debug_packet(request, request->proxy, false);
        return 1;
 }
 
@@ -3582,12 +3570,11 @@ STATE_MACHINE_DECL(proxy_wait_for_reply)
                request->num_proxied_requests++;
 
                rad_assert(request->proxy_listener != NULL);;
-               DEBUG_PACKET(request, request->proxy, 1);
                FR_STATS_TYPE_INC(home->stats.total_requests);
                home->last_packet_sent = now.tv_sec;
                request->proxy_retransmit = now;
-               request->proxy_listener->send(request->proxy_listener,
-                                             request);
+               request->proxy_listener->send(request->proxy_listener, request);
+               debug_packet(request, request->proxy, false);
                break;
 
        case FR_ACTION_TIMER:
@@ -3935,8 +3922,6 @@ static void request_coa_originate(REQUEST *request)
        coa->packet->timestamp = coa->proxy->timestamp; /* for max_request_time */
        coa->delay = 0;         /* need to calculate a new delay */
 
-       DEBUG_PACKET(coa, coa->proxy, 1);
-
        coa->process = coa_wait_for_reply;
 #ifdef DEBUG_STATE_MACHINE
        if (debug_flag) printf("(%u) ********\tSTATE %s C-%s -> C-%s\t********\n", request->number, __FUNCTION__,
@@ -3951,6 +3936,7 @@ static void request_coa_originate(REQUEST *request)
        FR_STATS_TYPE_INC(coa->home_server->stats.total_requests);
        coa->home_server->last_packet_sent = coa->proxy->timestamp.tv_sec;
        coa->proxy_listener->send(coa->proxy_listener, coa);
+       debug_packet(coa, coa->proxy, false);
 }
 
 

diff --git a/src/main/valuepair.c b/src/main/valuepair.c
index 497964f..b3a555b 100644 (file)
--- a/src/main/valuepair.c
+++ b/src/main/valuepair.c
@@ -696,7 +696,7 @@ void rdebug_pair(int level, REQUEST *request, VALUE_PAIR *vp)
        RDEBUGX(level, "%s", buffer);
 }
 
-/** Print a list of valuepairs to the request list.
+/** Print a list of VALUE_PAIRs.
  *
  * @param[in] level Debug level (1-4).
  * @param[in] request to read logging params from.
@@ -722,6 +722,33 @@ void rdebug_pair_list(int level, REQUEST *request, VALUE_PAIR *vp)
        REXDENT();
 }
 
+/** Print a list of protocol VALUE_PAIRs.
+ *
+ * @param[in] level Debug level (1-4).
+ * @param[in] request to read logging params from.
+ * @param[in] vp to print.
+ */
+void rdebug_proto_pair_list(int level, REQUEST *request, VALUE_PAIR *vp)
+{
+       vp_cursor_t cursor;
+       char buffer[256];
+       if (!vp || !request || !request->log.func) return;
+
+       if (!radlog_debug_enabled(L_DBG, level, request)) return;
+
+       RINDENT();
+       for (vp = fr_cursor_init(&cursor, &vp);
+            vp;
+            vp = fr_cursor_next(&cursor)) {
+               VERIFY_VP(vp);
+               if ((vp->da->vendor == 0) &&
+                   ((vp->da->attr & 0xFFFF) > 0xff)) continue;
+               vp_prints(buffer, sizeof(buffer), vp);
+               RDEBUGX(level, "%s", buffer);
+       }
+       REXDENT();
+}
+
 /** Return a VP from the specified request.
  *
  * @param out where to write the pointer to the resolved VP.