track original_recv_time properly

diff --git a/src/lib/io/channel.h b/src/lib/io/channel.h
index 16f3237f19703fb8dd19444e80ede314ca8fae93..58543e846cfdb25d9eabce802a6e2a1f1db8d4af 100644 (file)
--- a/src/lib/io/channel.h
+++ b/src/lib/io/channel.h
@@ -94,7 +94,7 @@ typedef struct fr_channel_data_t {
 
        union {
                struct {
-                       fr_time_t               *start_time;    //!< time original request started (network -> worker)
+                       fr_time_t               *recv_time;     //!< time original request was received (network -> worker)
                        fr_dlist_t              list;           //!< list of unprocessed packets for the worker
                } request;
 

diff --git a/src/lib/io/io.h b/src/lib/io/io.h
index dd0865a1bfb438f4aa9760e882348a268dab3324..cebddef97249e77640b3ecf6f877d6316d17b64e 100644 (file)
--- a/src/lib/io/io.h
+++ b/src/lib/io/io.h
@@ -174,13 +174,14 @@ typedef size_t (*fr_io_nak_t)(void const *instance, uint8_t *const packet, size_
  *
  * @param[in] instance         the context for this function
  * @param[out] packet_ctx      Where to write a newly allocated packet_ctx struct containing request specific data.
+ * @param[in,out] recv_time    A pointer to a time when the packet was received
  * @param[in,out] buffer       the buffer where the raw packet will be written to (or read from)
  * @param[in] buffer_len       the length of the buffer
  * @return
  *     - <0 on error
  *     - >=0 length of the data read or written.
  */
-typedef ssize_t (*fr_io_data_read_t)(void const *instance, void **packet_ctx, uint8_t *buffer, size_t buffer_len);
+typedef ssize_t (*fr_io_data_read_t)(void const *instance, void **packet_ctx, fr_time_t **recv_time, uint8_t *buffer, size_t buffer_len);
 
 /** Write a socket.
  *

diff --git a/src/lib/io/network.c b/src/lib/io/network.c
index ee580fa3637ef3a31653bcf12279e5c022ee13f1..3ceb9a37bd8889404ac34aeb626544f17b70cafe 100644 (file)
--- a/src/lib/io/network.c
+++ b/src/lib/io/network.c
@@ -299,9 +299,6 @@ static int fr_network_send_request(fr_network_t *nr, fr_channel_data_t *cd)
 }
 
 
-static fr_time_t start_time = 0;
-
-
 /** Read a packet from the network.
  *
  * @param[in] el       the event list.
@@ -315,6 +312,7 @@ static void fr_network_read(UNUSED fr_event_list_t *el, int sockfd, UNUSED int f
        fr_network_t *nr = talloc_parent(s);
        ssize_t data_size;
        fr_channel_data_t *cd;
+       fr_time_t *recv_time;
 
        rad_assert(s->listen->app_io->fd(s->listen->app_io_instance) == sockfd);
 
@@ -347,7 +345,7 @@ static void fr_network_read(UNUSED fr_event_list_t *el, int sockfd, UNUSED int f
         *      network side knows that it needs to close the
         *      connection.
         */
-       data_size = s->listen->app_io->read(s->listen->app_io_instance, &cd->packet_ctx, cd->m.data, cd->m.rb_size);
+       data_size = s->listen->app_io->read(s->listen->app_io_instance, &cd->packet_ctx, &recv_time, cd->m.data, cd->m.rb_size);
        if (data_size == 0) {
                fr_log(nr->log, L_DBG_ERR, "got no data from transport read");
 
@@ -381,12 +379,14 @@ static void fr_network_read(UNUSED fr_event_list_t *el, int sockfd, UNUSED int f
        /*
         *      Initialize the rest of the fields of the channel data.
         */
-       cd->m.when = fr_time();
+       if (recv_time) {
+               cd->m.when = *recv_time;
+       } else {
+               cd->m.when = fr_time();
+       }
        cd->priority = 0;
        cd->listen = s->listen;
-       cd->request.start_time = &start_time; /* @todo - set by transport */
-
-       start_time = cd->m.when;
+       cd->request.recv_time = recv_time;
 
        (void) fr_message_alloc(s->ms, &cd->m, data_size);
 

diff --git a/src/lib/io/worker.c b/src/lib/io/worker.c
index 062d44974f6e123a17866038a6baf0c25a651f87..0bdae208d5f4d7f5769508f325446d57a9af0f35 100644 (file)
--- a/src/lib/io/worker.c
+++ b/src/lib/io/worker.c
@@ -659,8 +659,9 @@ static REQUEST *fr_worker_get_request(fr_worker_t *worker, fr_time_t now)
                 *      This message has asynchronously aged out while it was
                 *      in the queue.  Delete it, and go get another one.
                 */
-               if (cd->request.start_time && (cd->m.when != *cd->request.start_time)) {
-                       fr_log(worker->log, L_DBG, "\t%sIGNORING old message", worker->name);
+               if (cd->request.recv_time && (cd->m.when != *cd->request.recv_time)) {
+                       fr_log(worker->log, L_DBG, "\t%sIGNORING old message: was %zd now %zd", worker->name,
+                               *cd->request.recv_time, cd->m.when);
                        fr_worker_nak(worker, cd, fr_time());
                        cd = NULL;
                }
@@ -694,7 +695,7 @@ static REQUEST *fr_worker_get_request(fr_worker_t *worker, fr_time_t now)
         *      processing this message.
         */
        request->async->channel = cd->channel.ch;
-       request->async->original_recv_time = cd->request.start_time;
+       request->async->original_recv_time = cd->request.recv_time;
        request->async->recv_time = cd->m.when;
        request->async->el = worker->el;
        request->number = worker->number++;
@@ -728,7 +729,7 @@ nak:
        /*
         *      Hoist run-time checks here.
         */
-       if (!cd->request.start_time) request->async->original_recv_time = &request->async->recv_time;
+       if (!cd->request.recv_time) request->async->original_recv_time = &request->async->recv_time;
 
        /*
         *      We're done with this message.

diff --git a/src/modules/proto_radius/proto_radius_udp.c b/src/modules/proto_radius/proto_radius_udp.c
index 54b90b8be07999580fbdfb1687060ce53e8a6e81..d2c7f4c0fbecbcf373d6e3f7c9f151fe98edca41 100644 (file)
--- a/src/modules/proto_radius/proto_radius_udp.c
+++ b/src/modules/proto_radius/proto_radius_udp.c
@@ -144,7 +144,7 @@ static RADCLIENT *mod_client(UNUSED void const *instance, void const *packet_ctx
        return address->client;
 }
 
-static ssize_t mod_read(void const *instance, void **packet_ctx, uint8_t *buffer, size_t buffer_len)
+static ssize_t mod_read(void const *instance, void **packet_ctx, fr_time_t **recv_time, uint8_t *buffer, size_t buffer_len)
 {
        proto_radius_udp_t const        *inst = talloc_get_type_abort(instance, proto_radius_udp_t);
 
@@ -227,6 +227,7 @@ static ssize_t mod_read(void const *instance, void **packet_ctx, uint8_t *buffer
        }
 
        *packet_ctx = track;
+       *recv_time = &track->timestamp;
 
        return packet_len;
 }
@@ -246,7 +247,7 @@ static ssize_t mod_write(void const *instance, void *packet_ctx,
         *      The original packet has changed.  Suppress the write,
         *      as the client will never accept the response.
         */
-       if (track->timestamp > request_time) return buffer_len;
+       if (track->timestamp != request_time) return buffer_len;
 
        /*
         *      Figure out when we've sent the reply.

diff --git a/src/tests/util/radius_schedule_test.c b/src/tests/util/radius_schedule_test.c
index be1029fabd6772cf618951129ccc12581458ee73..d4219fcdc01a87caf11a56d6bd11eb36daa49c49 100644 (file)
--- a/src/tests/util/radius_schedule_test.c
+++ b/src/tests/util/radius_schedule_test.c
@@ -130,7 +130,9 @@ static int test_open(void *ctx)
        return 0;
 }
 
-static ssize_t test_read(void const *ctx, UNUSED void **packet_ctx, uint8_t *buffer, size_t buffer_len)
+static fr_time_t start_time;
+
+static ssize_t test_read(void const *ctx, UNUSED void **packet_ctx, fr_time_t **recv_time, uint8_t *buffer, size_t buffer_len)
 {
        ssize_t                 data_size;
        fr_listen_test_t        *io_ctx = talloc_get_type_abort(ctx, fr_listen_test_t);
@@ -146,6 +148,9 @@ static ssize_t test_read(void const *ctx, UNUSED void **packet_ctx, uint8_t *buf
        tpc.id = buffer[1];
        memcpy(tpc.vector, buffer + 4, sizeof(tpc.vector));
 
+       start_time = fr_time();
+       *recv_time = &start_time;
+
        return data_size;
 }