Added trigger statistics to Prometheus-style outputs, fixed executable triggers not correctly responding with the default on execv fail

lib/procs.cpp

@@ -366,6 +366,19 @@ pid_t Util::Procs::StartPiped(const char * const * argv, int * fdin, int * fdout
     }
     //Because execvp requires a char* const* and we have a const char* const*
     execvp(argv[0], (char* const*)argv);
+    /*LTS-START*/
+    char * trggr = getenv("MIST_TRIGGER");
+    if (trggr && strlen(trggr)){
+      ERROR_MSG("%s trigger failed to execute %s: %s", trggr, argv[0], strerror(errno));
+      JSON::Value j;
+      j["trigger_fail"] = trggr;
+      Socket::UDPConnection uSock;
+      uSock.SetDestination(UDP_API_HOST, UDP_API_PORT);
+      uSock.SendNow(j.toString());
+      std::cout << getenv("MIST_TRIG_DEF");
+      exit(42);
+    }
+    /*LTS-END*/
     ERROR_MSG("execvp failed for process %s, reason: %s", argv[0], strerror(errno));
     exit(42);
   } else if (pid == -1) {

lib/triggers.cpp

@@ -20,10 +20,22 @@
 #include "procs.h"       //for StartPiped
 #include "shared_memory.h"
 #include "util.h"
+#include "timing.h"
 #include <string.h> //for strncmp
 
 namespace Triggers{
 
+
+  static void submitTriggerStat(const std::string trigger, uint64_t millis, bool ok){
+    JSON::Value j;
+    j["trigger_stat"]["name"] = trigger;
+    j["trigger_stat"]["ms"] = Util::bootMS()-millis;
+    j["trigger_stat"]["ok"] = ok;
+    Socket::UDPConnection uSock;
+    uSock.SetDestination(UDP_API_HOST, UDP_API_PORT);
+    uSock.SendNow(j.toString());
+  }
+
   ///\brief Handles a trigger by sending a payload to a destination.
   ///\param trigger Trigger event type.
   ///\param value Destination. This can be an (HTTP)URL, or an absolute path to a binary/script
@@ -31,6 +43,7 @@ namespace Triggers{
   ///\param sync If true, handler is executed blocking and uses the response data.
   ///\returns String, false if further processing should be aborted.
   std::string handleTrigger(const std::string &trigger, const std::string &value, const std::string &payload, int sync, const std::string &defaultResponse){
+    uint64_t tStartMs = Util::bootMS();
     if (!value.size()){
       WARN_MSG("Trigger requested with empty destination");
       return "true";
@@ -42,21 +55,29 @@ namespace Triggers{
       DL.setHeader("Content-Type", "text/plain");
       HTTP::URL url(value);
       if (DL.post(url, payload, sync) && sync && DL.isOk()){
+        submitTriggerStat(trigger, tStartMs, true);
         return DL.data();
       }
       FAIL_MSG("Trigger failed to execute (%s), using default response: %s", DL.getStatusText().c_str(), defaultResponse.c_str());
+      submitTriggerStat(trigger, tStartMs, false);
       return defaultResponse;
     }else{// send payload to stdin of newly forked process
       int fdIn = -1;
       int fdOut = -1;
+      int fdErr = 2;
 
       char *argv[3];
       argv[0] = (char *)value.c_str();
       argv[1] = (char *)trigger.c_str();
       argv[2] = NULL;
-      pid_t myProc = Util::Procs::StartPiped(argv, &fdIn, &fdOut, 0); // start new process and return stdin file desc.
+      setenv("MIST_TRIGGER", trigger.c_str(), 1);
-      if (fdIn == -1 || fdOut == -1){// verify fdIn
+      setenv("MIST_TRIG_DEF", defaultResponse.c_str(), 1);
-        FAIL_MSG("StartPiped returned invalid fd");
+      pid_t myProc = Util::Procs::StartPiped(argv, &fdIn, &fdOut, &fdErr); // start new process and return stdin file desc.
+      unsetenv("MIST_TRIGGER");
+      unsetenv("MIST_TRIG_DEF");
+      if (fdIn == -1 || fdOut == -1 || myProc == -1){
+        FAIL_MSG("Could not execute trigger executable: %s", strerror(errno));
+        submitTriggerStat(trigger, tStartMs, false);
         return defaultResponse;
       }
       write(fdIn, payload.data(), payload.size());
@@ -87,13 +108,16 @@ namespace Triggers{
         fclose(outFile);
         free(fileBuf);
         close(fdOut);
-        if (counter >= 150){
+        if (counter >= 150 && !ret.size()){
           WARN_MSG("Using default trigger response: %s", defaultResponse.c_str());
+          submitTriggerStat(trigger, tStartMs, false);
           return defaultResponse;
         }
+        submitTriggerStat(trigger, tStartMs, true);
         return ret;
       }
       close(fdOut);
+      submitTriggerStat(trigger, tStartMs, true);
       return defaultResponse;
     }
   }

src/controller/controller_api.cpp

@@ -433,6 +433,23 @@ static void removeDuplicateProtocols(){
 }
 
 void Controller::handleAPICommands(JSON::Value & Request, JSON::Value & Response){
+  /*LTS-START*/
+  //These are only used internally. We abort further processing if encountered.
+  if (Request.isMember("trigger_stat")){
+    JSON::Value & tStat = Request["trigger_stat"];
+    if (tStat.isMember("name") && tStat.isMember("ms")){
+      Controller::triggerLog & tLog = Controller::triggerStats[tStat["name"].asStringRef()];
+      tLog.totalCount++;
+      tLog.ms += tStat["ms"].asInt();
+      if (!tStat.isMember("ok") || !tStat["ok"].asBool()){tLog.failCount++;}
+    }
+    return;
+  }
+  if (Request.isMember("trigger_fail")){
+    Controller::triggerStats[Request["trigger_fail"].asStringRef()].failCount++;
+    return;
+  }
+  /*LTS-END*/
   //Parse config and streams from the request.
   if (Request.isMember("config") && Request["config"].isObject()){
     const JSON::Value & in = Request["config"];

src/controller/controller_statistics.cpp

@@ -43,6 +43,8 @@
 
 std::map<Controller::sessIndex, Controller::statSession> Controller::sessions; ///< list of sessions that have statistics data available
 std::map<unsigned long, Controller::sessIndex> Controller::connToSession; ///< Map of socket IDs to session info.
+
+std::map<std::string, Controller::triggerLog> Controller::triggerStats; ///< Holds prometheus stats for trigger executions
 bool Controller::killOnExit = KILL_ON_EXIT;
 tthread::mutex Controller::statsMutex;
 unsigned int Controller::maxConnsPerIP = 0;
@@ -1611,6 +1613,18 @@ void Controller::handlePrometheus(HTTP::Parser & H, Socket::Connection & conn, i
     response << "# TYPE mist_shm_used gauge\n";
     response << "mist_shm_used " << (shm_total - shm_free) << "\n\n";
 
+    if (Controller::triggerStats.size()){
+      response << "# HELP mist_trigger_count Total executions for the given trigger\n";
+      response << "# HELP mist_trigger_time Total execution time in millis for the given trigger\n";
+      response << "# HELP mist_trigger_fails Total failed executions for the given trigger\n";
+      for (std::map<std::string, Controller::triggerLog>::iterator it = Controller::triggerStats.begin(); it != Controller::triggerStats.end(); it++){
+        response << "mist_trigger_count{trigger=\"" << it->first << "\"} " << it->second.totalCount << "\n";
+        response << "mist_trigger_time{trigger=\"" << it->first << "\"} " << it->second.ms << "\n";
+        response << "mist_trigger_fails{trigger=\"" << it->first << "\"} " << it->second.failCount << "\n";
+      }
+      response << "\n";
+    }
+
     {//Scope for shortest possible blocking of statsMutex
       tthread::lock_guard<tthread::mutex> guard(statsMutex);
       //collect the data first
@@ -1699,6 +1713,14 @@ void Controller::handlePrometheus(HTTP::Parser & H, Socket::Connection & conn, i
     resp["shm_total"] = shm_total;
     resp["shm_used"] = (shm_total - shm_free);
     resp["logs"] = Controller::logCounter;
+    if (Controller::triggerStats.size()){
+      for (std::map<std::string, Controller::triggerLog>::iterator it = Controller::triggerStats.begin(); it != Controller::triggerStats.end(); it++){
+        JSON::Value & tVal = resp["triggers"][it->first];
+        tVal["count"] = it->second.totalCount;
+        tVal["ms"] = it->second.ms;
+        tVal["fails"] = it->second.failCount;
+      }
+    }
     {//Scope for shortest possible blocking of statsMutex
       tthread::lock_guard<tthread::mutex> guard(statsMutex);
       //collect the data first

src/controller/controller_statistics.h

@@ -119,6 +119,15 @@ namespace Controller {
   extern std::map<unsigned long, sessIndex> connToSession;
   extern tthread::mutex statsMutex;
 
+
+  struct triggerLog {
+    uint64_t totalCount;
+    uint64_t failCount;
+    uint64_t ms;
+  };
+
+  extern std::map<std::string, triggerLog> triggerStats;
+
   std::set<std::string> getActiveStreams(const std::string & prefix = "");
   void parseStatistics(char * data, size_t len, unsigned int id);
   void killStatistics(char * data, size_t len, unsigned int id);