From fa7ae246ca4779b9351792f4f1ac3e5852ff4844 Mon Sep 17 00:00:00 2001
From: Craig Tiller <ctiller@google.com>
Date: Thu, 12 Oct 2017 09:37:57 -0700
Subject: [PATCH 1/2] Add call combiner stats

---
 src/core/lib/debug/stats_data.cc              |  5 +++++
 src/core/lib/debug/stats_data.h               |  8 ++++++++
 src/core/lib/debug/stats_data.yaml            |  7 ++++++-
 src/core/lib/debug/stats_data_bq_schema.sql   |  2 ++
 src/core/lib/iomgr/call_combiner.cc           |  3 +++
 .../performance/massage_qps_stats.py          |  2 ++
 .../performance/scenario_result_schema.json   | 20 +++++++++++++++++++
 7 files changed, 46 insertions(+), 1 deletion(-)

diff --git a/src/core/lib/debug/stats_data.cc b/src/core/lib/debug/stats_data.cc
index b4ae8f312cd..2271c87e568 100644
--- a/src/core/lib/debug/stats_data.cc
+++ b/src/core/lib/debug/stats_data.cc
@@ -104,6 +104,8 @@ const char *grpc_stats_counter_name[GRPC_STATS_COUNTER_COUNT] = {
     "combiner_locks_scheduled_items",
     "combiner_locks_scheduled_final_items",
     "combiner_locks_offloaded",
+    "call_combiner_locks_initiated",
+    "call_combiner_locks_scheduled_items",
     "executor_scheduled_short_items",
     "executor_scheduled_long_items",
     "executor_scheduled_to_self",
@@ -213,6 +215,9 @@ const char *grpc_stats_counter_doc[GRPC_STATS_COUNTER_COUNT] = {
     "Number of items scheduled against combiner locks",
     "Number of final items scheduled against combiner locks",
     "Number of combiner locks offloaded to different threads",
+    "Number of call combiner lock entries by process (first items queued to a "
+    "call combiner)",
+    "Number of items scheduled against call combiner locks",
     "Number of finite runtime closures scheduled against the executor (gRPC "
     "thread pool)",
     "Number of potentially infinite runtime closures scheduled against the "
diff --git a/src/core/lib/debug/stats_data.h b/src/core/lib/debug/stats_data.h
index d4c4437ca07..bfa5c1a61be 100644
--- a/src/core/lib/debug/stats_data.h
+++ b/src/core/lib/debug/stats_data.h
@@ -110,6 +110,8 @@ typedef enum {
   GRPC_STATS_COUNTER_COMBINER_LOCKS_SCHEDULED_ITEMS,
   GRPC_STATS_COUNTER_COMBINER_LOCKS_SCHEDULED_FINAL_ITEMS,
   GRPC_STATS_COUNTER_COMBINER_LOCKS_OFFLOADED,
+  GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_INITIATED,
+  GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_SHORT_ITEMS,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_LONG_ITEMS,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_TO_SELF,
@@ -407,6 +409,12 @@ typedef enum {
 #define GRPC_STATS_INC_COMBINER_LOCKS_OFFLOADED(exec_ctx) \
   GRPC_STATS_INC_COUNTER((exec_ctx),                      \
                          GRPC_STATS_COUNTER_COMBINER_LOCKS_OFFLOADED)
+#define GRPC_STATS_INC_CALL_COMBINER_LOCKS_INITIATED(exec_ctx) \
+  GRPC_STATS_INC_COUNTER((exec_ctx),                           \
+                         GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_INITIATED)
+#define GRPC_STATS_INC_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS(exec_ctx) \
+  GRPC_STATS_INC_COUNTER(                                            \
+      (exec_ctx), GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS)
 #define GRPC_STATS_INC_EXECUTOR_SCHEDULED_SHORT_ITEMS(exec_ctx) \
   GRPC_STATS_INC_COUNTER((exec_ctx),                            \
                          GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_SHORT_ITEMS)
diff --git a/src/core/lib/debug/stats_data.yaml b/src/core/lib/debug/stats_data.yaml
index 00e81e74e20..d12c8df663f 100644
--- a/src/core/lib/debug/stats_data.yaml
+++ b/src/core/lib/debug/stats_data.yaml
@@ -245,6 +245,12 @@
   doc: Number of final items scheduled against combiner locks
 - counter: combiner_locks_offloaded
   doc: Number of combiner locks offloaded to different threads
+# call combiner locks
+- counter: call_combiner_locks_initiated
+  doc: Number of call combiner lock entries by process
+       (first items queued to a call combiner)
+- counter: call_combiner_locks_scheduled_items
+  doc: Number of items scheduled against call combiner locks
 # executor
 - counter: executor_scheduled_short_items
   doc: Number of finite runtime closures scheduled against the executor
@@ -282,4 +288,3 @@
 - counter: cq_ev_queue_transient_pop_failures
   doc: Number of times NULL was popped out of completion queue's event queue
        even though the event queue was not empty
-
diff --git a/src/core/lib/debug/stats_data_bq_schema.sql b/src/core/lib/debug/stats_data_bq_schema.sql
index f34b0c25a03..5e541b9181e 100644
--- a/src/core/lib/debug/stats_data_bq_schema.sql
+++ b/src/core/lib/debug/stats_data_bq_schema.sql
@@ -79,6 +79,8 @@ combiner_locks_initiated_per_iteration:FLOAT,
 combiner_locks_scheduled_items_per_iteration:FLOAT,
 combiner_locks_scheduled_final_items_per_iteration:FLOAT,
 combiner_locks_offloaded_per_iteration:FLOAT,
+call_combiner_locks_initiated_per_iteration:FLOAT,
+call_combiner_locks_scheduled_items_per_iteration:FLOAT,
 executor_scheduled_short_items_per_iteration:FLOAT,
 executor_scheduled_long_items_per_iteration:FLOAT,
 executor_scheduled_to_self_per_iteration:FLOAT,
diff --git a/src/core/lib/iomgr/call_combiner.cc b/src/core/lib/iomgr/call_combiner.cc
index bab3df021a6..8b08d307a19 100644
--- a/src/core/lib/iomgr/call_combiner.cc
+++ b/src/core/lib/iomgr/call_combiner.cc
@@ -21,6 +21,7 @@
 #include <inttypes.h>
 
 #include <grpc/support/log.h>
+#include "src/core/lib/debug/stats.h"
 
 grpc_tracer_flag grpc_call_combiner_trace =
     GRPC_TRACER_INITIALIZER(false, "call_combiner");
@@ -73,7 +74,9 @@ void grpc_call_combiner_start(grpc_exec_ctx* exec_ctx,
     gpr_log(GPR_DEBUG, "  size: %" PRIdPTR " -> %" PRIdPTR, prev_size,
             prev_size + 1);
   }
+  GRPC_STATS_INC_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS(exec_ctx);
   if (prev_size == 0) {
+    GRPC_STATS_INC_CALL_COMBINER_LOCKS_INITIATED(exec_ctx);
     if (GRPC_TRACER_ON(grpc_call_combiner_trace)) {
       gpr_log(GPR_DEBUG, "  EXECUTING IMMEDIATELY");
     }
diff --git a/tools/run_tests/performance/massage_qps_stats.py b/tools/run_tests/performance/massage_qps_stats.py
index e0b6ce6ba63..eadd17db8ee 100644
--- a/tools/run_tests/performance/massage_qps_stats.py
+++ b/tools/run_tests/performance/massage_qps_stats.py
@@ -101,6 +101,8 @@ def massage_qps_stats(scenario_result):
     stats["core_combiner_locks_scheduled_items"] = massage_qps_stats_helpers.counter(core_stats, "combiner_locks_scheduled_items")
     stats["core_combiner_locks_scheduled_final_items"] = massage_qps_stats_helpers.counter(core_stats, "combiner_locks_scheduled_final_items")
     stats["core_combiner_locks_offloaded"] = massage_qps_stats_helpers.counter(core_stats, "combiner_locks_offloaded")
+    stats["core_call_combiner_locks_initiated"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_locks_initiated")
+    stats["core_call_combiner_locks_scheduled_items"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_locks_scheduled_items")
     stats["core_executor_scheduled_short_items"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_short_items")
     stats["core_executor_scheduled_long_items"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_long_items")
     stats["core_executor_scheduled_to_self"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_to_self")
diff --git a/tools/run_tests/performance/scenario_result_schema.json b/tools/run_tests/performance/scenario_result_schema.json
index f11e6359f65..1d726539b90 100644
--- a/tools/run_tests/performance/scenario_result_schema.json
+++ b/tools/run_tests/performance/scenario_result_schema.json
@@ -515,6 +515,16 @@
         "name": "core_combiner_locks_offloaded", 
         "type": "INTEGER"
       }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_locks_initiated", 
+        "type": "INTEGER"
+      }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_locks_scheduled_items", 
+        "type": "INTEGER"
+      }, 
       {
         "mode": "NULLABLE", 
         "name": "core_executor_scheduled_short_items", 
@@ -1327,6 +1337,16 @@
         "name": "core_combiner_locks_offloaded", 
         "type": "INTEGER"
       }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_locks_initiated", 
+        "type": "INTEGER"
+      }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_locks_scheduled_items", 
+        "type": "INTEGER"
+      }, 
       {
         "mode": "NULLABLE", 
         "name": "core_executor_scheduled_short_items", 

From 7befe5d8e568da23edab19b02b953a33dd973e9f Mon Sep 17 00:00:00 2001
From: Craig Tiller <ctiller@google.com>
Date: Thu, 12 Oct 2017 09:53:02 -0700
Subject: [PATCH 2/2] Add counters

---
 src/core/lib/debug/stats_data.cc              |  4 ++++
 src/core/lib/debug/stats_data.h               |  7 +++++++
 src/core/lib/debug/stats_data.yaml            |  4 ++++
 src/core/lib/debug/stats_data_bq_schema.sql   |  2 ++
 src/core/lib/iomgr/call_combiner.cc           |  2 ++
 .../performance/massage_qps_stats.py          |  2 ++
 .../performance/scenario_result_schema.json   | 20 +++++++++++++++++++
 7 files changed, 41 insertions(+)

diff --git a/src/core/lib/debug/stats_data.cc b/src/core/lib/debug/stats_data.cc
index 2271c87e568..5d737c56cbf 100644
--- a/src/core/lib/debug/stats_data.cc
+++ b/src/core/lib/debug/stats_data.cc
@@ -106,6 +106,8 @@ const char *grpc_stats_counter_name[GRPC_STATS_COUNTER_COUNT] = {
     "combiner_locks_offloaded",
     "call_combiner_locks_initiated",
     "call_combiner_locks_scheduled_items",
+    "call_combiner_set_notify_on_cancel",
+    "call_combiner_cancelled",
     "executor_scheduled_short_items",
     "executor_scheduled_long_items",
     "executor_scheduled_to_self",
@@ -218,6 +220,8 @@ const char *grpc_stats_counter_doc[GRPC_STATS_COUNTER_COUNT] = {
     "Number of call combiner lock entries by process (first items queued to a "
     "call combiner)",
     "Number of items scheduled against call combiner locks",
+    "Number of times a cancellation callback was set on a call combiner",
+    "Number of times a call combiner was cancelled",
     "Number of finite runtime closures scheduled against the executor (gRPC "
     "thread pool)",
     "Number of potentially infinite runtime closures scheduled against the "
diff --git a/src/core/lib/debug/stats_data.h b/src/core/lib/debug/stats_data.h
index bfa5c1a61be..031942df5c5 100644
--- a/src/core/lib/debug/stats_data.h
+++ b/src/core/lib/debug/stats_data.h
@@ -112,6 +112,8 @@ typedef enum {
   GRPC_STATS_COUNTER_COMBINER_LOCKS_OFFLOADED,
   GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_INITIATED,
   GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS,
+  GRPC_STATS_COUNTER_CALL_COMBINER_SET_NOTIFY_ON_CANCEL,
+  GRPC_STATS_COUNTER_CALL_COMBINER_CANCELLED,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_SHORT_ITEMS,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_LONG_ITEMS,
   GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_TO_SELF,
@@ -415,6 +417,11 @@ typedef enum {
 #define GRPC_STATS_INC_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS(exec_ctx) \
   GRPC_STATS_INC_COUNTER(                                            \
       (exec_ctx), GRPC_STATS_COUNTER_CALL_COMBINER_LOCKS_SCHEDULED_ITEMS)
+#define GRPC_STATS_INC_CALL_COMBINER_SET_NOTIFY_ON_CANCEL(exec_ctx) \
+  GRPC_STATS_INC_COUNTER(                                           \
+      (exec_ctx), GRPC_STATS_COUNTER_CALL_COMBINER_SET_NOTIFY_ON_CANCEL)
+#define GRPC_STATS_INC_CALL_COMBINER_CANCELLED(exec_ctx) \
+  GRPC_STATS_INC_COUNTER((exec_ctx), GRPC_STATS_COUNTER_CALL_COMBINER_CANCELLED)
 #define GRPC_STATS_INC_EXECUTOR_SCHEDULED_SHORT_ITEMS(exec_ctx) \
   GRPC_STATS_INC_COUNTER((exec_ctx),                            \
                          GRPC_STATS_COUNTER_EXECUTOR_SCHEDULED_SHORT_ITEMS)
diff --git a/src/core/lib/debug/stats_data.yaml b/src/core/lib/debug/stats_data.yaml
index d12c8df663f..af4553028e3 100644
--- a/src/core/lib/debug/stats_data.yaml
+++ b/src/core/lib/debug/stats_data.yaml
@@ -251,6 +251,10 @@
        (first items queued to a call combiner)
 - counter: call_combiner_locks_scheduled_items
   doc: Number of items scheduled against call combiner locks
+- counter: call_combiner_set_notify_on_cancel
+  doc: Number of times a cancellation callback was set on a call combiner
+- counter: call_combiner_cancelled
+  doc: Number of times a call combiner was cancelled
 # executor
 - counter: executor_scheduled_short_items
   doc: Number of finite runtime closures scheduled against the executor
diff --git a/src/core/lib/debug/stats_data_bq_schema.sql b/src/core/lib/debug/stats_data_bq_schema.sql
index 5e541b9181e..04b6d471f63 100644
--- a/src/core/lib/debug/stats_data_bq_schema.sql
+++ b/src/core/lib/debug/stats_data_bq_schema.sql
@@ -81,6 +81,8 @@ combiner_locks_scheduled_final_items_per_iteration:FLOAT,
 combiner_locks_offloaded_per_iteration:FLOAT,
 call_combiner_locks_initiated_per_iteration:FLOAT,
 call_combiner_locks_scheduled_items_per_iteration:FLOAT,
+call_combiner_set_notify_on_cancel_per_iteration:FLOAT,
+call_combiner_cancelled_per_iteration:FLOAT,
 executor_scheduled_short_items_per_iteration:FLOAT,
 executor_scheduled_long_items_per_iteration:FLOAT,
 executor_scheduled_to_self_per_iteration:FLOAT,
diff --git a/src/core/lib/iomgr/call_combiner.cc b/src/core/lib/iomgr/call_combiner.cc
index 8b08d307a19..0ba32a1e463 100644
--- a/src/core/lib/iomgr/call_combiner.cc
+++ b/src/core/lib/iomgr/call_combiner.cc
@@ -138,6 +138,7 @@ void grpc_call_combiner_stop(grpc_exec_ctx* exec_ctx,
 void grpc_call_combiner_set_notify_on_cancel(grpc_exec_ctx* exec_ctx,
                                              grpc_call_combiner* call_combiner,
                                              grpc_closure* closure) {
+  GRPC_STATS_INC_CALL_COMBINER_SET_NOTIFY_ON_CANCEL(exec_ctx);
   while (true) {
     // Decode original state.
     gpr_atm original_state = gpr_atm_acq_load(&call_combiner->cancel_state);
@@ -182,6 +183,7 @@ void grpc_call_combiner_set_notify_on_cancel(grpc_exec_ctx* exec_ctx,
 void grpc_call_combiner_cancel(grpc_exec_ctx* exec_ctx,
                                grpc_call_combiner* call_combiner,
                                grpc_error* error) {
+  GRPC_STATS_INC_CALL_COMBINER_CANCELLED(exec_ctx);
   while (true) {
     gpr_atm original_state = gpr_atm_acq_load(&call_combiner->cancel_state);
     grpc_error* original_error = decode_cancel_state_error(original_state);
diff --git a/tools/run_tests/performance/massage_qps_stats.py b/tools/run_tests/performance/massage_qps_stats.py
index eadd17db8ee..48c57581a52 100644
--- a/tools/run_tests/performance/massage_qps_stats.py
+++ b/tools/run_tests/performance/massage_qps_stats.py
@@ -103,6 +103,8 @@ def massage_qps_stats(scenario_result):
     stats["core_combiner_locks_offloaded"] = massage_qps_stats_helpers.counter(core_stats, "combiner_locks_offloaded")
     stats["core_call_combiner_locks_initiated"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_locks_initiated")
     stats["core_call_combiner_locks_scheduled_items"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_locks_scheduled_items")
+    stats["core_call_combiner_set_notify_on_cancel"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_set_notify_on_cancel")
+    stats["core_call_combiner_cancelled"] = massage_qps_stats_helpers.counter(core_stats, "call_combiner_cancelled")
     stats["core_executor_scheduled_short_items"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_short_items")
     stats["core_executor_scheduled_long_items"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_long_items")
     stats["core_executor_scheduled_to_self"] = massage_qps_stats_helpers.counter(core_stats, "executor_scheduled_to_self")
diff --git a/tools/run_tests/performance/scenario_result_schema.json b/tools/run_tests/performance/scenario_result_schema.json
index 1d726539b90..b00c2eed165 100644
--- a/tools/run_tests/performance/scenario_result_schema.json
+++ b/tools/run_tests/performance/scenario_result_schema.json
@@ -525,6 +525,16 @@
         "name": "core_call_combiner_locks_scheduled_items", 
         "type": "INTEGER"
       }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_set_notify_on_cancel", 
+        "type": "INTEGER"
+      }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_cancelled", 
+        "type": "INTEGER"
+      }, 
       {
         "mode": "NULLABLE", 
         "name": "core_executor_scheduled_short_items", 
@@ -1347,6 +1357,16 @@
         "name": "core_call_combiner_locks_scheduled_items", 
         "type": "INTEGER"
       }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_set_notify_on_cancel", 
+        "type": "INTEGER"
+      }, 
+      {
+        "mode": "NULLABLE", 
+        "name": "core_call_combiner_cancelled", 
+        "type": "INTEGER"
+      }, 
       {
         "mode": "NULLABLE", 
         "name": "core_executor_scheduled_short_items",