Extend milestone api time tracking to remap. (#8520)

Author: SolidWallOfCode

proxy/http/HttpSM.cc

@@ -98,41 +98,6 @@ using lbw = ts::LocalBufferWriter<256>;
 
 namespace
 {
-/// Update the milestone state given the milestones and timer.
-inline void
-milestone_update_api_time(TransactionMilestones &milestones, ink_hrtime &api_timer)
-{
-  // Bit of funkiness - we set @a api_timer to be the negative value when we're tracking
-  // non-active API time. In that case we need to make a note of it and flip the value back
-  // to positive.
-  if (api_timer) {
-    ink_hrtime delta;
-    bool active = api_timer >= 0;
-    if (!active) {
-      api_timer = -api_timer;
-    }
-    delta     = Thread::get_hrtime_updated() - api_timer;
-    api_timer = 0;
-    // Zero or negative time is a problem because we want to signal *something* happened
-    // vs. no API activity at all. This can happen due to graininess or real time
-    // clock adjustment.
-    if (delta <= 0) {
-      delta = 1;
-    }
-
-    if (0 == milestones[TS_MILESTONE_PLUGIN_TOTAL]) {
-      milestones[TS_MILESTONE_PLUGIN_TOTAL] = milestones[TS_MILESTONE_SM_START];
-    }
-    milestones[TS_MILESTONE_PLUGIN_TOTAL] += delta;
-    if (active) {
-      if (0 == milestones[TS_MILESTONE_PLUGIN_ACTIVE]) {
-        milestones[TS_MILESTONE_PLUGIN_ACTIVE] = milestones[TS_MILESTONE_SM_START];
-      }
-      milestones[TS_MILESTONE_PLUGIN_ACTIVE] += delta;
-    }
-  }
-}
-
 // Unique state machine identifier
 std::atomic<int64_t> next_sm_id(0);
 
@@ -1449,7 +1414,7 @@ HttpSM::state_common_wait_for_transform_read(HttpTransformInfo *t_info, HttpSMHa
 //    with setting and changing the default_handler
 //    function.  As such, this is an entry point
 //    and needs to handle the reentrancy counter and
-//    deallocation the state machine if necessary
+//    deallocation of the state machine if necessary
 //
 int
 HttpSM::state_api_callback(int event, void *data)
@@ -1459,7 +1424,7 @@ HttpSM::state_api_callback(int event, void *data)
   ink_assert(reentrancy_count >= 0);
   reentrancy_count++;
 
-  milestone_update_api_time(milestones, api_timer);
+  this->milestone_update_api_time();
 
   STATE_ENTER(&HttpSM::state_api_callback, event);
 
@@ -1509,7 +1474,7 @@ HttpSM::state_api_callout(int event, void *data)
     // the transaction got an event without the plugin calling TsHttpTxnReenable().
     // The call chain does not recurse here if @a api_timer < 0 which means this call
     // is the first from an event dispatch in this case.
-    milestone_update_api_time(milestones, api_timer);
+    this->milestone_update_api_time();
   }
 
   switch (event) {
@@ -1586,7 +1551,7 @@ plugins required to work with sni_routing.
 
       hook->invoke(TS_EVENT_HTTP_READ_REQUEST_HDR + cur_hook_id, this);
       if (api_timer > 0) { // true if the hook did not call TxnReenable()
-        milestone_update_api_time(milestones, api_timer);
+        this->milestone_update_api_time();
         api_timer = -Thread::get_hrtime(); // set in order to track non-active callout duration
         // which means that if we get back from the invoke with api_timer < 0 we're already
         // tracking a non-complete callout from a chain so just let it ride. It will get cleaned
@@ -8514,3 +8479,38 @@ HttpSM::get_server_version(HTTPHdr &hdr) const
 {
   return this->server_txn->get_proxy_ssn()->get_version(hdr);
 }
+
+/// Update the milestone state given the milestones and timer.
+void
+HttpSM::milestone_update_api_time()
+{
+  // Bit of funkiness - we set @a api_timer to be the negative value when we're tracking
+  // non-active API time. In that case we need to make a note of it and flip the value back
+  // to positive.
+  if (api_timer) {
+    ink_hrtime delta;
+    bool active = api_timer >= 0;
+    if (!active) {
+      api_timer = -api_timer;
+    }
+    delta     = Thread::get_hrtime_updated() - api_timer;
+    api_timer = 0;
+    // Zero or negative time is a problem because we want to signal *something* happened
+    // vs. no API activity at all. This can happen due to graininess or real time
+    // clock adjustment.
+    if (delta <= 0) {
+      delta = 1;
+    }
+
+    if (0 == milestones[TS_MILESTONE_PLUGIN_TOTAL]) {
+      milestones[TS_MILESTONE_PLUGIN_TOTAL] = milestones[TS_MILESTONE_SM_START];
+    }
+    milestones[TS_MILESTONE_PLUGIN_TOTAL] += delta;
+    if (active) {
+      if (0 == milestones[TS_MILESTONE_PLUGIN_ACTIVE]) {
+        milestones[TS_MILESTONE_PLUGIN_ACTIVE] = milestones[TS_MILESTONE_SM_START];
+      }
+      milestones[TS_MILESTONE_PLUGIN_ACTIVE] += delta;
+    }
+  }
+}

proxy/http/HttpSM.h

@@ -204,6 +204,7 @@ class PostDataBuffers
 class HttpSM : public Continuation, public PluginUserArgs<TS_USER_ARGS_TXN>
 {
   friend class HttpPagesHandler;
+  friend class HttpTransact;
 
 public:
   HttpSM();
@@ -522,6 +523,9 @@ class HttpSM : public Continuation, public PluginUserArgs<TS_USER_ARGS_TXN>
   int find_http_resp_buffer_size(int64_t cl);
   int64_t server_transfer_init(MIOBuffer *buf, int hdr_size);
 
+  /// Update the milestones to track time spent in the plugin API.
+  void milestone_update_api_time();
+
 public:
   // TODO:  Now that bodies can be empty, should the body counters be set to -1 ? TS-2213
   // Stats & Logging Info

proxy/http/HttpTransact.cc

@@ -8355,6 +8355,19 @@ ink_local_time()
 //
 // The stat functions
 //
+
+void
+HttpTransact::milestone_start_api_time(State *s)
+{
+  s->state_machine->api_timer = Thread::get_hrtime_updated();
+}
+
+void
+HttpTransact::milestone_update_api_time(State *s)
+{
+  s->state_machine->milestone_update_api_time();
+}
+
 void
 HttpTransact::histogram_response_document_size(State *s, int64_t doc_size)
 {

proxy/http/HttpTransact.h

@@ -1071,6 +1071,8 @@ class HttpTransact
                                          int64_t origin_server_request_body_size, int origin_server_response_header_size,
                                          int64_t origin_server_response_body_size, int pushed_response_header_size,
                                          int64_t pushed_response_body_size, const TransactionMilestones &milestones);
+  static void milestone_start_api_time(State *s);
+  static void milestone_update_api_time(State *s);
   static void histogram_request_document_size(State *s, int64_t size);
   static void histogram_response_document_size(State *s, int64_t size);
   static void user_agent_connection_speed(State *s, ink_hrtime transfer_time, int64_t nbytes);

proxy/http/remap/RemapPlugins.cc

@@ -53,7 +53,10 @@ RemapPlugins::run_plugin(RemapPluginInst *plugin)
     _s->os_response_plugin_inst = plugin;
   }
 
+  HttpTransact::milestone_start_api_time(_s);
   plugin_retcode = plugin->doRemap(reinterpret_cast<TSHttpTxn>(_s->state_machine), &rri);
+  HttpTransact::milestone_update_api_time(_s);
+
   // TODO: Deal with negative return codes here
   if (plugin_retcode < 0) {
     plugin_retcode = TSREMAP_NO_REMAP;