more debug messages for tracking state

diff --git a/src/lib/io/master.c b/src/lib/io/master.c
index c9579e52e876a2086c9246a189c0d24ca34fa93c..5b8156298f07651007aeac4f8ea46ec24a808f8e 100644 (file)
--- a/src/lib/io/master.c
+++ b/src/lib/io/master.c
@@ -1716,6 +1716,11 @@ have_client:
                                        return 0;
                                }
 
+                               if (track->discard) {
+                                       DEBUG("Ignoring transmit from client %s - we previously received a newer / conflicting packet", client->radclient->shortname);
+                                       return 0;
+                               }
+
                                if (!track->reply) {
                                        fr_assert(!track->finished);
                                        DEBUG("Ignoring retransmit from client %s - we are still processing the request", client->radclient->shortname);
@@ -2326,16 +2331,21 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
        fr_client_t *radclient;
        fr_listen_t *child;
        fr_event_list_t *el;
+       char const *name;
 
        get_inst(li, &inst, &thread, &connection, &child);
 
        client = track->client;
        if (connection) {
                el = connection->el;
+               name = connection->name;
        } else {
                el = thread->el;
+               name = li->name;
        }
 
+       DEBUG3("Processing reply for %s", name);
+
        /*
         *      A fully defined client means that we just send the reply.
         */
@@ -2345,15 +2355,13 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                track->finished = true;
 
                /*
-                *      The request later received a conflicting
-                *      packet, so we discard this one.
+                *      The request received a conflicting packet, so we
+                *      discard this one.
                 */
                if (fr_time_neq(track->timestamp, request_time) || track->discard) {
                        fr_assert(track->packets > 0);
                        track->packets--;
-
-                       DEBUG3("Suppressing reply as we have a newer packet");
-
+                       DEBUG3("Suppressing reply as we have a newer / conflicing packet from the same source");
                        track->discard = true;
                        goto setup_timer;
                }
@@ -2365,6 +2373,7 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                 *      "do not respond" reply for a period of time.
                 */
                if ((buffer_len == 1) || track->do_not_respond) {
+                       DEBUG3("Not sending response to request - it is marked as 'do not respond'");
                        track->do_not_respond = true;
                        goto setup_timer;
                }
@@ -2376,6 +2385,7 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                packet_len = inst->app_io->write(child, track, request_time,
                                                 buffer, buffer_len, written);
                if (packet_len <= 0) {
+                       ERROR("Failed writing the reply - not sending any response on %s", name);
                        track->discard = true;
                        packet_expiry_timer(el->tl, fr_time_wrap(0), track);
                        return packet_len;
@@ -2387,6 +2397,7 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                 *      the expiry timer at that point.
                 */
                if ((size_t) packet_len < buffer_len) {
+                       DEBUG3("Partial write (%zd < %zu)", packet_len, buffer_len);
                        return packet_len;
                }
 
@@ -2394,7 +2405,10 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                 *      We're not tracking duplicates, so just expire
                 *      the packet now.
                 */
-               if (!inst->app_io->track_duplicates) goto setup_timer;
+               if (!inst->app_io->track_duplicates) {
+                       DEBUG3("Not tracking duplicates - expiring the request");
+                       goto setup_timer;
+               }
 
                /*
                 *      Cache the reply packet if we're doing dedup.
@@ -2403,6 +2417,7 @@ static ssize_t mod_write(fr_listen_t *li, void *packet_ctx, fr_time_t request_ti
                 *      already filled out.  So we don't do that twice.
                 */
                if (!track->reply) {
+                       DEBUG3("Caching reply");
                        MEM(track->reply = talloc_memdup(track, buffer, buffer_len));
                        track->reply_len = buffer_len;
                }