librdmacm/cmatose: add performance counters

Add counters to time connection establishment rates.

Signed-off-by: Sean Hefty <sean.hefty@intel.com>
git-svn-id: svn://openib.tc.cornell.edu/gen1/trunk@2238 ad392aa1-c5ef-ae45-8dd8-e69d62a5ef86

diff --git a/ulp/librdmacm/examples/cmatose/cmatose.c b/ulp/librdmacm/examples/cmatose/cmatose.c
index c7d8981..e3ce6e6 100644 (file)
--- a/ulp/librdmacm/examples/cmatose/cmatose.c
+++ b/ulp/librdmacm/examples/cmatose/cmatose.c
@@ -45,6 +45,8 @@ struct cmatest_node {
        struct ibv_cq           *cq[2];\r
        struct ibv_mr           *mr;\r
        void                            *mem;\r
+       LARGE_INTEGER           start_time[4];\r
+       LARGE_INTEGER           end_time[4];\r
 };\r
 \r
 enum cq_index {\r
@@ -75,6 +77,7 @@ static uint8_t tos;
 static uint8_t migrate = 0;\r
 static char *dst_addr;\r
 static char *src_addr;\r
+static LARGE_INTEGER start_time[2], end_time[2];\r
 \r
 static int create_message(struct cmatest_node *node)\r
 {\r
@@ -213,6 +216,7 @@ static int addr_handler(struct cmatest_node *node)
 {\r
        int ret;\r
 \r
+       QueryPerformanceCounter(&node->end_time[0]);\r
        if (set_tos) {\r
                ret = rdma_set_option(node->cma_id, RDMA_OPTION_ID,\r
                                      RDMA_OPTION_ID_TOS, &tos, sizeof tos);\r
@@ -220,6 +224,7 @@ static int addr_handler(struct cmatest_node *node)
                        printf("cmatose: set TOS option failed: 0x%x\n", ret);\r
        }\r
 \r
+       QueryPerformanceCounter(&node->start_time[1]);\r
        ret = rdma_resolve_route(node->cma_id, 2000);\r
        if (ret) {\r
                printf("cmatose: resolve route failed: 0x%x\n", ret);\r
@@ -233,6 +238,8 @@ static int route_handler(struct cmatest_node *node)
        struct rdma_conn_param conn_param;\r
        int ret;\r
 \r
+       QueryPerformanceCounter(&node->end_time[1]);\r
+       QueryPerformanceCounter(&node->start_time[2]);\r
        ret = init_node(node);\r
        if (ret)\r
                goto err;\r
@@ -240,11 +247,13 @@ static int route_handler(struct cmatest_node *node)
        ret = post_recvs(node);\r
        if (ret)\r
                goto err;\r
+       QueryPerformanceCounter(&node->end_time[2]);\r
 \r
        memset(&conn_param, 0, sizeof conn_param);\r
        conn_param.responder_resources = 1;\r
        conn_param.initiator_depth = 1;\r
        conn_param.retry_count = 5;\r
+       QueryPerformanceCounter(&node->start_time[3]);\r
        ret = rdma_connect(node->cma_id, &conn_param);\r
        if (ret) {\r
                printf("cmatose: failure connecting: 0x%x\n", ret);\r
@@ -271,6 +280,7 @@ static int connect_handler(struct rdma_cm_id *cma_id)
        node->cma_id = cma_id;\r
        cma_id->context = node;\r
 \r
+       QueryPerformanceCounter(&node->start_time[2]);\r
        ret = init_node(node);\r
        if (ret)\r
                goto err2;\r
@@ -278,10 +288,12 @@ static int connect_handler(struct rdma_cm_id *cma_id)
        ret = post_recvs(node);\r
        if (ret)\r
                goto err2;\r
+       QueryPerformanceCounter(&node->end_time[2]);\r
 \r
        memset(&conn_param, 0, sizeof conn_param);\r
        conn_param.responder_resources = 1;\r
        conn_param.initiator_depth = 1;\r
+       QueryPerformanceCounter(&node->start_time[3]);\r
        ret = rdma_accept(node->cma_id, &conn_param);\r
        if (ret) {\r
                printf("cmatose: failure accepting: 0x%x\n", ret);\r
@@ -314,6 +326,7 @@ static int cma_handler(struct rdma_cm_id *cma_id, struct rdma_cm_event *event)
                break;\r
        case RDMA_CM_EVENT_ESTABLISHED:\r
                ((struct cmatest_node *) cma_id->context)->connected = 1;\r
+               QueryPerformanceCounter(&((struct cmatest_node *) cma_id->context)->end_time[3]);\r
                test.connects_left--;\r
                break;\r
        case RDMA_CM_EVENT_ADDR_ERROR:\r
@@ -431,6 +444,9 @@ static int connect_events(void)
        while (test.connects_left && !err) {\r
                err = rdma_get_cm_event(test.channel, &event);\r
                if (!err) {\r
+                       if (!dst_addr && !start_time[0].QuadPart)\r
+                               QueryPerformanceCounter(&start_time[0]);\r
+\r
                        cma_handler(event->id, event);\r
                        rdma_ack_cm_event(event);\r
                } else {\r
@@ -438,6 +454,7 @@ static int connect_events(void)
                        ret = err;\r
                }\r
        }\r
+       QueryPerformanceCounter(&end_time[0]);\r
 \r
        return ret;\r
 }\r
@@ -450,6 +467,9 @@ static int disconnect_events(void)
        while (test.disconnects_left && !err) {\r
                err = rdma_get_cm_event(test.channel, &event);\r
                if (!err) {\r
+                       if (dst_addr && !start_time[1].QuadPart)\r
+                               QueryPerformanceCounter(&start_time[1]);\r
+\r
                        cma_handler(event->id, event);\r
                        rdma_ack_cm_event(event);\r
                } else {\r
@@ -457,6 +477,7 @@ static int disconnect_events(void)
                        ret = err;\r
                }\r
        }\r
+       QueryPerformanceCounter(&end_time[1]);\r
 \r
        return ret;\r
 }\r
@@ -576,6 +597,8 @@ static int run_server(void)
        }\r
 \r
        printf("cmatose: disconnecting\n");\r
+       QueryPerformanceCounter(&start_time[1]);\r
+\r
        for (i = 0; i < connections; i++) {\r
                if (!test.nodes[i].connected)\r
                        continue;\r
@@ -611,7 +634,10 @@ static int run_client(void)
        test.dst_in.sin_port = port;\r
 \r
        printf("cmatose: connecting\n");\r
+       QueryPerformanceCounter(&start_time[0]);\r
+\r
        for (i = 0; i < connections; i++) {\r
+               QueryPerformanceCounter(&test.nodes[i].start_time[0]);\r
                ret = rdma_resolve_addr(test.nodes[i].cma_id,\r
                                        src_addr ? test.src_addr : NULL,\r
                                        test.dst_addr, 2000);\r
@@ -649,6 +675,7 @@ static int run_client(void)
                if (ret)\r
                        goto out;\r
        }\r
+\r
 disc:\r
        ret2 = disconnect_events();\r
        if (ret2)\r
@@ -657,6 +684,62 @@ out:
        return ret;\r
 }\r
 \r
+static UINT64 sum_counters(int index)\r
+{\r
+       UINT64 total = 0;\r
+       int i;\r
+\r
+       for (i = 0; i < connections; i++) {\r
+               total += (test.nodes[i].end_time[index].QuadPart -\r
+                                 test.nodes[i].start_time[index].QuadPart);\r
+       }\r
+       return total;\r
+}\r
+\r
+static void show_perf(void)\r
+{\r
+       LARGE_INTEGER freq;\r
+       double run_time;\r
+       int i;\r
+\r
+       QueryPerformanceFrequency(&freq);\r
+       run_time = (double) (end_time[0].QuadPart - start_time[0].QuadPart) /\r
+                          (double) freq.QuadPart;\r
+       printf("%d connection%s in %.4f seconds (%.0f connections/second)\n",\r
+                  connections, connections == 1 ? "" : "s", run_time,\r
+                  (double) connections / run_time);\r
+\r
+       run_time = (double) (end_time[1].QuadPart - start_time[1].QuadPart) /\r
+                          (double) freq.QuadPart;\r
+       printf("%d disconnect%s in %.4f seconds (%.0f disconnects/second)\n",\r
+                  connections, connections == 1 ? "" : "s", run_time,\r
+                  (double) connections / run_time);\r
+\r
+       if (dst_addr) {\r
+               run_time = (double) sum_counters(0) / (double) freq.QuadPart;\r
+               printf("sum resolve address times %.4f seconds (%.2f ms average)\n",\r
+                          run_time, run_time * 1000 / (double) connections);\r
+\r
+               run_time = (double) sum_counters(1) / (double) freq.QuadPart;\r
+               printf("sum resolve route times %.4f seconds (%.2f ms average)\n",\r
+                          run_time, run_time * 1000 / (double) connections);\r
+       }\r
+\r
+       run_time = (double) sum_counters(2) / (double) freq.QuadPart;\r
+       printf("sum initialize node times %.4f seconds (%.2f ms average)\n",\r
+                  run_time, run_time * 1000 / (double) connections);\r
+\r
+       run_time = (double) sum_counters(3) / (double) freq.QuadPart;\r
+       printf("sum connect/accept times %.4f seconds (%.2f ms average)\n",\r
+                  run_time, run_time * 1000 / (double) connections);\r
+\r
+       if (dst_addr) {\r
+               run_time = (double) (sum_counters(3) - sum_counters(2)) / (double) freq.QuadPart;\r
+               printf("est. adjusted connect times %.4f seconds (%.2f ms average)\n",\r
+                          run_time, run_time * 1000 / (double) connections);\r
+       }\r
+}\r
+\r
 int __cdecl main(int argc, char **argv)\r
 {\r
        int op, ret;\r
@@ -722,6 +805,8 @@ int __cdecl main(int argc, char **argv)
                ret = run_server();\r
 \r
        printf("test complete\n");\r
+       show_perf();\r
+\r
        destroy_nodes();\r
        rdma_destroy_event_channel(test.channel);\r
 \r