From c41fd7ea188bdcab363c5c3d4966fef0f75f394b Mon Sep 17 00:00:00 2001
From: Vitaliy Filippov <vitalif@yourcmc.ru>
Date: Sat, 29 Feb 2020 01:46:03 +0300
Subject: [PATCH] Measure sending subops with data

---
 osd.cpp      |  6 ++++++
 osd.h        |  5 ++++-
 osd_send.cpp | 14 +++++++++++++-
 3 files changed, 23 insertions(+), 2 deletions(-)

diff --git a/osd.cpp b/osd.cpp
index 890209c42..f2169ac67 100644
--- a/osd.cpp
+++ b/osd.cpp
@@ -48,6 +48,12 @@ osd_t::osd_t(blockstore_config_t & config, blockstore_t *bs, ring_loop_t *ringlo
                 subop_stat_sum[i] = 0;
             }
         }
+        if (send_stat_count != 0)
+        {
+            printf("avg latency to send subops with data: %ld us\n", send_stat_sum/send_stat_count);
+            send_stat_count = 0;
+            send_stat_sum = 0;
+        }
     });
     this->bs_block_size = bs->get_block_size();
     // FIXME: use bitmap granularity instead
diff --git a/osd.h b/osd.h
index e32cad53d..bc81fc5f1 100644
--- a/osd.h
+++ b/osd.h
@@ -31,7 +31,7 @@
 #define CL_WRITE_READY 1
 #define CL_WRITE_REPLY 2
 #define CL_WRITE_DATA 3
-#define MAX_EPOLL_EVENTS 16
+#define MAX_EPOLL_EVENTS 64
 #define OSD_OP_INLINE_BUF_COUNT 4
 
 #define PEER_CONNECTING 1
@@ -97,6 +97,7 @@ struct osd_primary_op_data_t;
 struct osd_op_t
 {
     timeval tv_begin;
+    timeval tv_send;
     int op_type = OSD_OP_IN;
     int peer_fd;
     osd_any_op_t req;
@@ -213,6 +214,8 @@ class osd_t
     uint64_t op_stat_count[OSD_OP_MAX+1] = { 0 };
     uint64_t subop_stat_sum[OSD_OP_MAX+1] = { 0 };
     uint64_t subop_stat_count[OSD_OP_MAX+1] = { 0 };
+    uint64_t send_stat_sum = 0;
+    uint64_t send_stat_count = 0;
 
     // methods
 
diff --git a/osd_send.cpp b/osd_send.cpp
index bfad67600..e4964633b 100644
--- a/osd_send.cpp
+++ b/osd_send.cpp
@@ -36,6 +36,7 @@ void osd_t::send_replies()
             cl.outbox.pop_front();
             if (cl.write_op->op_type == OSD_OP_OUT)
             {
+                gettimeofday(&cl.write_op->tv_send, NULL);
                 cl.write_buf = &cl.write_op->req.buf;
                 cl.write_remaining = OSD_PACKET_SIZE;
                 cl.write_state = CL_WRITE_REPLY;
@@ -59,7 +60,6 @@ void osd_t::send_replies()
         cl.write_iov.iov_len = cl.write_remaining;
         cl.write_msg.msg_iov = &cl.write_iov;
         cl.write_msg.msg_iovlen = 1;
-        // FIXME: This is basically a busy-loop. It may be better to add epoll here(?)
         data->callback = [this, peer_fd](ring_data_t *data) { handle_send(data, peer_fd); };
         my_uring_prep_sendmsg(sqe, peer_fd, &cl.write_msg, 0);
         cl.write_state = cl.write_state | SQE_SENT;
@@ -107,6 +107,18 @@ void osd_t::handle_send(ring_data_t *data, int peer_fd)
                     }
                     else
                     {
+                        // Measure subops with data
+                        if (cur_op->req.hdr.opcode == OSD_OP_SECONDARY_STABILIZE ||
+                            cur_op->req.hdr.opcode == OSD_OP_SECONDARY_WRITE)
+                        {
+                            timeval tv_end;
+                            gettimeofday(&tv_end, NULL);
+                            send_stat_count++;
+                            send_stat_sum += (
+                                (tv_end.tv_sec - cl.write_op->tv_send.tv_sec)*1000000 +
+                                tv_end.tv_usec - cl.write_op->tv_send.tv_usec
+                            );
+                        }
                         cl.sent_ops[cl.write_op->req.hdr.id] = cl.write_op;
                     }
                     cl.write_op = NULL;