dtest: fix test to ack data before time stamp for accurate perf results

Add rdma_write with immediat on last message and returned message to
insure all data is received. The existing write time was not accurate.

Fix signaling rate support, default = 10.

Signed-off-by: Arlin Davis <arlin.r.davis@intel.com>

diff --git a/test/dtest/dtest.c b/test/dtest/dtest.c
index ec8b94aa1280b96af1e844c27fe9dbad0c09a571..534e875d363924384cebe80c377a1a77ddfe9ede 100755 (executable)
--- a/test/dtest/dtest.c
+++ b/test/dtest/dtest.c
@@ -101,6 +101,7 @@
 
 /* Header files needed for DAT/uDAPL */
 #include "dat2/udat.h"
+#include "dat2/dat_ib_extensions.h"
 
 /* definitions */
 #define SERVER_CONN_QUAL  45248
@@ -195,11 +196,11 @@ struct dt_time ts;
 /* defaults */
 static int failed = 0;
 static int uni_direction = 0;
-static int align_data=0;
-static int performance_times = 1;
+static int align_data=1;
+static int performance_times = 0;
 static int connected = 0;
 static int burst = 100;
-static int signal_rate = 2;
+static int signal_rate = 10;
 static int server = 1;
 static int verbose = 0;
 static int polling = 0;
@@ -443,7 +444,7 @@ int main(int argc, char **argv)
                signal_rate = burst;
 
        rq_cnt = MSG_BUF_COUNT + (burst);
-       sq_cnt = MSG_BUF_COUNT + (burst/signal_rate) + MAX_RDMA_RD;
+       sq_cnt = MSG_BUF_COUNT + MAX_RDMA_RD + signal_rate;
 
        if (!server) {
                printf("%d Running as client - %s\n", getpid(), provider);
@@ -468,8 +469,8 @@ int main(int argc, char **argv)
                }
        }
        memset(&ts, 0, sizeof(struct dt_time));
-       LOGPRINTF("%d Allocated RDMA buffers (r:%p,s:%p) len %d \n",
-                 getpid(), rbuf, sbuf, buf_len);
+       printf("%d Allocated RDMA buffers (r:%p,s:%p) len %d burst %d sig_rate %d sq %d rq %d\n",
+                 getpid(), rbuf, sbuf, buf_len, burst, signal_rate, sq_cnt, rq_cnt);
 
        if (posix_memalign((void**)&p_rmr_rcv, 4096, 4096) ||
            posix_memalign((void**)&p_rmr_snd, 4096, 4096)) {
@@ -640,6 +641,9 @@ int main(int argc, char **argv)
                } else
                        LOGPRINTF("%d do_rdma_read_with_msg complete\n", getpid());
 
+       }
+
+       if (!write_only) {
 
                /*********** PING PING messages ************/
                ret = do_ping_pong_msg();
@@ -732,7 +736,7 @@ complete:
        if (ts.rtt)
                printf("%d: Message RTT: Total=%6.2lf usec, %d bursts, itime=%6.2lf usec, pc=%d\n",
                        getpid(), ts.rtt, burst, ts.rtt / burst, poll_count);
-       if (ts.rdma_wr) {
+       if (ts.rdma_wr && (!server || (server && !uni_direction))) {
                int msgs = uni_direction ? burst : burst * 2;
 
                printf("\n%d: RDMA write (%s): Total=%6.2lf usec, itime=%6.2lf us, poll=%d, %d x %d, %4.2lf MB/sec\n",
@@ -849,8 +853,7 @@ send_msg(void *data,
                        return (DAT_ABORT);
 
                }
-               if (event.event_data.dto_completion_event_data.status !=
-                   DAT_SUCCESS) {
+               if (event.event_data.dto_completion_event_data.status != (int)DAT_SUCCESS) {
                        fprintf(stderr, "%d: ERROR: DTO event status %s\n",
                                getpid(), DT_RetToStr(ret));
                        return (DAT_ABORT);
@@ -1343,6 +1346,8 @@ DAT_RETURN do_rdma_write_with_msg(void)
        DAT_DTO_COOKIE cookie;
        DAT_RETURN ret;
        int i, flags = DAT_COMPLETION_SUPPRESS_FLAG;
+       DAT_DTO_COMPLETION_EVENT_DATA *dto_event = &event.event_data.dto_completion_event_data;
+       DAT_IB_EXTENSION_EVENT_DATA *ext_event = (DAT_IB_EXTENSION_EVENT_DATA *)event.event_extension_data;
 
        printf("\n %d RDMA WRITE DATA with SEND MSG\n\n", getpid());
 
@@ -1370,6 +1375,7 @@ DAT_RETURN do_rdma_write_with_msg(void)
                          l_iov[i].segment_length);
        }
 
+
        if  (uni_direction && server)
                goto done;
 
@@ -1380,22 +1386,23 @@ DAT_RETURN do_rdma_write_with_msg(void)
 
                sprintf(&sbuf[25], "rdma writes completed == %d", i+1);
                sbuf[buf_len-1] = i;
-               if ((i == (burst - 1)) || (i % (burst/signal_rate) == 0))
+               if (!((i+1) % signal_rate))
                        flags =  DAT_COMPLETION_DEFAULT_FLAG;
                else
                        flags = DAT_COMPLETION_SUPPRESS_FLAG;
 
                cookie.as_64 = i;
-               ret = dat_ep_post_rdma_write(h_ep,      // ep_handle
-                                            MSG_IOV_COUNT,     // num_segments
-                                            l_iov,     // LMR
-                                            cookie,    // user_cookie
-                                            &r_iov,    // RMR
-                                            flags);
+
+               /* last message is write_immed with buf_len as immediate date */
+               if (i == (burst - 1)) {
+                       ret = dat_ib_post_rdma_write_immed(
+                               h_ep, MSG_IOV_COUNT, l_iov, cookie, &r_iov,  0x7777, flags);
+               } else {
+                       ret = dat_ep_post_rdma_write(
+                               h_ep, MSG_IOV_COUNT, l_iov, cookie, &r_iov, flags);
+               }
                if (ret != DAT_SUCCESS) {
-                       fprintf(stderr,
-                               "%d: ERROR: dat_ep_post_rdma_write() %s\n",
-                               getpid(), DT_RetToStr(ret));
+                       fprintf(stderr, "%d: ERROR: dat_rdma_write() %s\n", getpid(), DT_RetToStr(ret));
                        return (DAT_ABORT);
                }
                LOGPRINTF("%d rdma_write # %d completed\n", getpid(), i + 1);
@@ -1406,89 +1413,90 @@ DAT_RETURN do_rdma_write_with_msg(void)
                                          DTO_TIMEOUT,
                                          &rdma_wr_poll_count) != DAT_SUCCESS)
                                return (DAT_ABORT);
-                       if (event.event_data.dto_completion_event_data.user_cookie.as_64 != i) {
-                               fprintf(stderr, "ERROR rdma_write: cookie=" F64x" exp 0x%x\n",
-                                       event.event_data.dto_completion_event_data.user_cookie.as_64,i);
+                       if (dto_event->user_cookie.as_64 != i) {
+                               fprintf(stderr, "ERROR rdma_write: cookie= "F64x " exp 0x%x\n",
+                                       dto_event->user_cookie.as_64, i);
                                return (DAT_ABORT);
                        }
                }
        }
-       stop = get_time();
-       ts.rdma_wr = ((stop - start) * 1.0e6);
+
 done:
-       /*
-        *  Send RMR information a 2nd time to indicate completion
-        *  NOTE: already swapped to network order in connect_ep
-        */
-       printf("%d Sending RDMA WRITE completion message\n", getpid());
+       if ((!uni_direction) || (uni_direction && server)) {
+               /* Wait to RECEIVE the LAST message, immediate data expected */
+               if (collect_event(h_dto_rcv_evd,
+                                 &event,
+                                 DTO_TIMEOUT,
+                                 &rdma_wr_poll_count) != DAT_SUCCESS)
+                       return (DAT_ABORT);
 
-       ret = send_msg(p_rmr_snd,
-                      sizeof(DAT_RMR_TRIPLET),
-                      lmr_context_send_msg,
-                      cookie, DAT_COMPLETION_DEFAULT_FLAG);
+               if (event.event_number != (int)DAT_IB_DTO_EVENT ||
+                   ext_event->type != DAT_IB_RDMA_WRITE_IMMED_DATA ||
+                   ext_event->val.immed.data != 0x7777) {
+                       printf("unexpected event 0x%x, type 0x%x or idata 0x%x, waiting for WR-IMMED #0x%x\n",
+                              event.event_number, ext_event->type,
+                              ext_event->val.immed.data, DAT_IB_DTO_EVENT);
+                       return (DAT_ABORT);
+               }
+               recv_msg_index++;
 
-       if (ret != DAT_SUCCESS) {
-               fprintf(stderr, "%d Error send_msg: %s\n",
-                       getpid(), DT_RetToStr(ret));
-               return (ret);
-       } else {
-               LOGPRINTF("%d send_msg completed\n", getpid());
-       }
+               /* Send last message received ACK message back */
+               cookie.as_64 = 0x9999;
+               ret = send_msg(p_rmr_snd,
+                              sizeof(DAT_RMR_TRIPLET),
+                              lmr_context_send_msg,
+                              cookie, DAT_COMPLETION_SUPPRESS_FLAG);
+
+               if (ret != DAT_SUCCESS) {
+                       fprintf(stderr, "%d Error send_msg: %s\n",
+                               getpid(), DT_RetToStr(ret));
+                       return (ret);
+               } else {
+                       LOGPRINTF("%d send_msg completed\n", getpid());
+               }
 
-       /* inbound recv event, send completion's suppressed */
-       if (collect_event(h_dto_rcv_evd, 
-                         &event, 
-                         DTO_TIMEOUT, 
-                         &rdma_wr_poll_count) != DAT_SUCCESS)
-               return (DAT_ABORT);
-       
-       /* validate event number and status */
-       printf("%d inbound rdma_write; send message arrived!\n", getpid());
-       if (event.event_number != DAT_DTO_COMPLETION_EVENT) {
-               fprintf(stderr, "%d Error unexpected DTO event : %s\n",
-                       getpid(), DT_EventToStr(event.event_number));
-               return (DAT_ABORT);
        }
 
-       if ((event.event_data.dto_completion_event_data.transfered_length !=
-            sizeof(DAT_RMR_TRIPLET))
-           || (event.event_data.dto_completion_event_data.user_cookie.as_64 !=
-               recv_msg_index)) {
-               fprintf(stderr,
-                       "unexpected event data for receive: len=%d cookie=" F64x
-                       " exp %d/%d\n",
-                       (int)event.event_data.dto_completion_event_data.
-                       transfered_length,
-                       event.event_data.dto_completion_event_data.user_cookie.
-                       as_64, (int)sizeof(DAT_RMR_TRIPLET), recv_msg_index);
+       if (!uni_direction || !server) {
+               /* Wait for my LAST message ACK from remote side */
+               printf("%d waiting for my LAST message ACK from remote side\n", getpid());
+               if (collect_event(h_dto_rcv_evd,
+                                 &event,
+                                 DTO_TIMEOUT,
+                                 &rdma_wr_poll_count) != DAT_SUCCESS)
+                       return (DAT_ABORT);
 
-               return (DAT_ABORT);
-       }
+               printf("%d LAST rdma write ACK message arrived!\n", getpid());
+               if (event.event_number != DAT_DTO_COMPLETION_EVENT) {
+                       fprintf(stderr, "%d Error unexpected DTO event : %s\n",
+                               getpid(), DT_EventToStr(event.event_number));
+                       return (DAT_ABORT);
+               }
 
-       /* swap received RMR msg: network order to host order */
-       r_iov = p_rmr_rcv[recv_msg_index];
-       p_rmr_rcv[recv_msg_index].virtual_address =
-           ntohll(p_rmr_rcv[recv_msg_index].virtual_address);
-       p_rmr_rcv[recv_msg_index].segment_length =
-           ntohl(p_rmr_rcv[recv_msg_index].segment_length);
-       p_rmr_rcv[recv_msg_index].rmr_context =
-           ntohl(p_rmr_rcv[recv_msg_index].rmr_context);
+               if ((dto_event->transfered_length != sizeof(DAT_RMR_TRIPLET))
+                   || (dto_event->user_cookie.as_64 != recv_msg_index)) {
+                       fprintf(stderr,
+                               "unexpected event data for receive: len=%d cookie=" F64x" exp %d/%d\n",
+                               (int)dto_event->transfered_length, dto_event->user_cookie.as_64,
+                               (int)sizeof(DAT_RMR_TRIPLET), recv_msg_index);
+                       return (DAT_ABORT);
+               }
+               printf("%d LAST rdma_write message ACK received from remote \n", getpid());
+       }
 
-       printf("%d Received RMR from remote: "
-              "r_iov: r_key_ctx=%x,va=" F64x ",len=0x%x\n",
-              getpid(), p_rmr_rcv[recv_msg_index].rmr_context,
-              p_rmr_rcv[recv_msg_index].virtual_address,
-              p_rmr_rcv[recv_msg_index].segment_length);
+       stop = get_time();
+       ts.rdma_wr = ((stop - start) * 1.0e6);
 
-       LOGPRINTF("%d inbound rdma_write; send msg event SUCCESS!!\n",
-                 getpid());
+       LOGPRINTF("%d last rdma_write ACK'ed SUCCESS!!\n", getpid());
 
        if (server || (!server && !uni_direction))
                printf("%d %s RDMA write buffer contains: %s last byte=%d\n",
                       getpid(), server ? "SERVER:" : "CLIENT:", rbuf, rbuf[buf_len-1]);
 
-       recv_msg_index++;
+       if (server && uni_direction)
+               sleep(1);
 
+       recv_msg_index++;
        return (DAT_SUCCESS);
 }
 
@@ -1563,8 +1571,7 @@ DAT_RETURN do_rdma_read_with_msg(void)
                                user_cookie.as_64);
                        return (DAT_ABORT);
                }
-               if (event.event_data.dto_completion_event_data.status !=
-                   DAT_SUCCESS) {
+               if (event.event_data.dto_completion_event_data.status != (int)DAT_SUCCESS) {
                        fprintf(stderr, "%d: ERROR: DTO event status %s\n",
                                getpid(), DT_RetToStr(ret));
                        return (DAT_ABORT);
@@ -2185,7 +2192,7 @@ void print_usage(void)
        printf("P: provider name (default = OpenIB-cma)\n");
        printf("l: server lid (required ucm provider)\n");
        printf("q: server qpn (required ucm provider)\n");
-       printf("S: burst/signal_rate (default 100/2 = completion every 50 iterations\n");
+       printf("S: signal_rate (default=10, completion every 10 iterations\n");
        printf("\n");
 }