Latency traces

1 files changed, 11 insertions, 0 deletions

diff --git a/src/core/surface/completion_queue.c b/src/core/surface/completion_queue.c
index e818ccba48..5ca8f837df 100644
--- a/src/core/surface/completion_queue.c
+++ b/src/core/surface/completion_queue.c
@@ -42,6 +42,7 @@
 #include "src/core/surface/call.h"
 #include "src/core/surface/event_string.h"
 #include "src/core/surface/surface_trace.h"
+#include "src/core/profiling/timers.h"
 #include <grpc/support/alloc.h>
 #include <grpc/support/atm.h>
 #include <grpc/support/log.h>
@@ -184,6 +185,8 @@ grpc_event grpc_completion_queue_next(grpc_completion_queue *cc,
   gpr_timespec now;
   grpc_exec_ctx exec_ctx = GRPC_EXEC_CTX_INIT;
 
+  GRPC_TIMER_BEGIN(GRPC_PTAG_CQ_NEXT, 0);
+
   GRPC_API_TRACE(
       "grpc_completion_queue_next("
       "cc=%p, "
@@ -230,6 +233,9 @@ grpc_event grpc_completion_queue_next(grpc_completion_queue *cc,
   GRPC_SURFACE_TRACE_RETURNED_EVENT(cc, &ret);
   GRPC_CQ_INTERNAL_UNREF(cc, "next");
   grpc_exec_ctx_finish(&exec_ctx);
+
+  GRPC_TIMER_END(GRPC_PTAG_CQ_NEXT, 0);
+
   return ret;
 }
 
@@ -268,6 +274,8 @@ grpc_event grpc_completion_queue_pluck(grpc_completion_queue *cc, void *tag,
   int first_loop = 1;
   grpc_exec_ctx exec_ctx = GRPC_EXEC_CTX_INIT;
 
+  GRPC_TIMER_BEGIN(GRPC_PTAG_CQ_PLUCK, 0);
+
   GRPC_API_TRACE(
       "grpc_completion_queue_pluck("
       "cc=%p, tag=%p, "
@@ -333,6 +341,9 @@ done:
   GRPC_SURFACE_TRACE_RETURNED_EVENT(cc, &ret);
   GRPC_CQ_INTERNAL_UNREF(cc, "pluck");
   grpc_exec_ctx_finish(&exec_ctx);
+
+  GRPC_TIMER_END(GRPC_PTAG_CQ_PLUCK, 0);
+
   return ret;
 }