HPCC-16887 Control TxSummary level in ESP log

Add txSummaryLevel and txSummaryResourceReq to esp.xml and
use them to control TxSummary level and whether log TxSummary
for ESP resource requests or not.

Signed-off-by: wangkx <kevin.wang@lexisnexis.com>

configuration/xsds_xmls/experimental.xml

@@ -433,6 +433,8 @@
               logLevel="1"
               logRequests="false"
               logResponses="false"
+              txSummaryLevel="1"
+              txSummaryResourceReq="false"
               maxBacklogQueueSize="200"
               maxConcurrentThreads="0"
               maxRequestEntityLength="8000000"

esp/bindings/http/platform/httpbinding.cpp

@@ -503,7 +503,7 @@ bool EspHttpBinding::basicAuth(IEspContext* ctx)
 
     m_secmgr->updateSettings(*user,securitySettings, ctx->querySecureContext());
 
-    ctx->addTraceSummaryTimeStamp("basicAuth");
+    ctx->addTraceSummaryTimeStamp(LogMin, "basicAuth");
     return authorized;
 }
     

esp/bindings/http/platform/httpservice.cpp

@@ -329,11 +329,17 @@ int CEspHttpServer::processRequest()
                     methodName.setCharAt(methodName.length()-1, 0);
                 if (!stricmp(methodName.str(), "files"))
                 {
+                    if (!getTxSummaryResourceReq())
+                        ctx->cancelTxSummary();
                     checkInitEclIdeResponse(m_request, m_response);
                     return onGetFile(m_request.get(), m_response.get(), pathEx.str());
                 }
                 else if (!stricmp(methodName.str(), "xslt"))
+                {
+                    if (!getTxSummaryResourceReq())
+                        ctx->cancelTxSummary();
                     return onGetXslt(m_request.get(), m_response.get(), pathEx.str());
+                }
                 else if (!stricmp(methodName.str(), "body"))
                     return onGetMainWindow(m_request.get(), m_response.get());
                 else if (!stricmp(methodName.str(), "frame"))
@@ -490,7 +496,7 @@ int CEspHttpServer::processRequest()
                 else
                     unsupported();
             }
-            ctx->addTraceSummaryTimeStamp("handleHttp");
+            ctx->addTraceSummaryTimeStamp(LogMin, "handleHttp");
         }
     }
     catch(IEspHttpException* e)

esp/bindings/http/platform/httptransport.cpp

@@ -615,7 +615,7 @@ int CHttpMessage::receive(bool alwaysReadContent, IMultiException *me)
     if (isUpload())
         return 0;
 
-    m_context->addTraceSummaryValue("contLen", m_content_length);
+    m_context->addTraceSummaryValue(LogMin, "contLen", m_content_length);
     if(m_content_length > 0)
     {
         readContent();
@@ -1670,7 +1670,7 @@ int CHttpRequest::receive(IMultiException *me)
         }
     }
 
-    m_context->addTraceSummaryTimeStamp("rcv");
+    m_context->addTraceSummaryTimeStamp(LogMin, "rcv");
     return 0;
 }
 

esp/logging/loggingmanager/loggingmanager.cpp

@@ -165,7 +165,7 @@ bool CLoggingManager::updateLog(IEspContext& espContext, IEspUpdateLogRequestWra
     bool bRet = false;
     try
     {
-        espContext.addTraceSummaryTimeStamp("LMgr:startQLog");
+        espContext.addTraceSummaryTimeStamp(LogMin, "LMgr:startQLog");
         for (unsigned int x = 0; x < loggingAgentThreads.size(); x++)
         {
             IUpdateLogThread* loggingThread = loggingAgentThreads[x];
@@ -175,7 +175,7 @@ bool CLoggingManager::updateLog(IEspContext& espContext, IEspUpdateLogRequestWra
                 bRet = true;
             }
         }
-        espContext.addTraceSummaryTimeStamp("LMgr:endQLog");
+        espContext.addTraceSummaryTimeStamp(LogMin, "LMgr:endQLog");
     }
     catch (IException* e)
     {

esp/platform/espcfg.cpp

@@ -135,6 +135,8 @@ CEspConfig::CEspConfig(IProperties* inputs, IPropertyTree* envpt, IPropertyTree*
     m_options.logLevel = level ? atoi(level) : LogMin;
     m_options.logReq = m_cfg->getPropBool("@logRequests", true);
     m_options.logResp = m_cfg->getPropBool("@logResponses", false);
+    m_options.txSummaryLevel = m_cfg->getPropInt("@txSummaryLevel", LogMin);
+    m_options.txSummaryResourceReq = m_cfg->getPropBool("@txSummaryResourceReq", false);
     m_options.frameTitle.set(m_cfg->queryProp("@name"));
     m_options.slowProcessingTime = m_cfg->getPropInt("@slowProcessingTime", 30) * 1000; //in msec
 

esp/platform/espcfg.ipp

@@ -89,10 +89,12 @@ struct esp_option
     LogLevel logLevel;
     bool logReq;
     bool logResp;
+    LogLevel txSummaryLevel;
+    bool txSummaryResourceReq;
     StringAttr frameTitle;
     unsigned slowProcessingTime; //default 30 seconds
 
-    esp_option() : logReq(false), logResp(false), logLevel(1), slowProcessingTime(30000)
+    esp_option() : logReq(false), logResp(false), logLevel(LogMin), txSummaryLevel(LogMin), txSummaryResourceReq(false), slowProcessingTime(30000)
     { }
 };
 

esp/platform/espcontext.cpp

@@ -445,40 +445,46 @@ public:
         return m_txSummary.get();
     }
 
-    virtual void addTraceSummaryValue(const char *name, const char *value)
+    virtual void addTraceSummaryValue(LogLevel logLevel, const char *name, const char *value)
     {
-        if (m_txSummary)
+        if (m_txSummary && (getTxSummaryLevel() >= logLevel))
             m_txSummary->append(name, value);
     }
 
-    virtual void addTraceSummaryValue(const char *name, __int64 value)
+    virtual void addTraceSummaryValue(LogLevel logLevel, const char *name, __int64 value)
     {
-        if (m_txSummary)
+        if (m_txSummary && (getTxSummaryLevel() >= logLevel))
             m_txSummary->append(name, value);
     }
 
-    virtual void addTraceSummaryTimeStamp(const char *name)
+    virtual void addTraceSummaryTimeStamp(LogLevel logLevel, const char *name)
     {
-        if (m_txSummary && name && *name)
+        if (m_txSummary && (getTxSummaryLevel() >= logLevel) && name && *name)
             m_txSummary->append(name, m_txSummary->getElapsedTime(), "ms");
     }
     virtual void flushTraceSummary()
     {
-        if (m_txSummary)
-        {
-            updateTraceSummaryHeader();
+        updateTraceSummaryHeader();
+        if (m_txSummary && (getTxSummaryLevel() >= LogMin))
             m_txSummary->append("total", m_processingTime, "ms");
-        }
     }
-    virtual void addTraceSummaryCumulativeTime(const char* name, unsigned __int64 time)
+    virtual void addTraceSummaryCumulativeTime(LogLevel logLevel, const char* name, unsigned __int64 time)
     {
-        if (m_txSummary)
+        if (m_txSummary && (getTxSummaryLevel() >= logLevel))
             m_txSummary->updateTimer(name, time);
     }
     virtual CumulativeTimer* queryTraceSummaryCumulativeTimer(const char* name)
     {
         return (m_txSummary ? m_txSummary->queryTimer(name) : NULL);
     }
+    virtual void cancelTxSummary()
+    {
+        if (!m_txSummary)
+            return;
+
+        m_txSummary->clear();
+        m_txSummary.clear();
+    }
 
     virtual ESPSerializationFormat getResponseFormat(){return respSerializationFormat;}
     virtual void setResponseFormat(ESPSerializationFormat fmt){respSerializationFormat = fmt;}
@@ -580,7 +586,7 @@ bool CEspContext::isMethodAllowed(double version, const char* optional, const ch
 
 void CEspContext::updateTraceSummaryHeader()
 {
-    if (m_txSummary)
+    if (m_txSummary && (getTxSummaryLevel() >= LogMin))
     {
         m_txSummary->set("activeReqs", m_active);
         VStringBuffer user("%s%s%s", (queryUserId() ? queryUserId() : ""), (m_peer.length() ? "@" : ""), m_peer.str());
@@ -761,6 +767,20 @@ LogLevel getEspLogLevel(IEspContext* ctx)
     return LogMin;
 }
 
+LogLevel getTxSummaryLevel()
+{
+    if (getContainer())
+        return getContainer()->getTxSummaryLevel();
+    return LogMin;
+}
+
+bool getTxSummaryResourceReq()
+{
+    if (getContainer())
+        return getContainer()->getTxSummaryResourceReq();
+    return false;
+}
+
 bool getEspLogRequests()
 {
     if (getContainer())

esp/platform/espcontext.hpp

@@ -51,6 +51,8 @@ ESPHTTP_API LogLevel getEspLogLevel(IEspContext* );
 ESPHTTP_API LogLevel getEspLogLevel();
 ESPHTTP_API bool getEspLogRequests();
 ESPHTTP_API bool getEspLogResponses();
+ESPHTTP_API LogLevel getTxSummaryLevel();
+ESPHTTP_API bool getTxSummaryResourceReq();
 ESPHTTP_API unsigned getSlowProcessingTime();
 
 ESPHTTP_API void ESPLOG(IEspContext* ctx, LogLevel level, const char* fmt, ...) __attribute__((format(printf, 3, 4)));

esp/platform/espp.hpp

@@ -56,6 +56,8 @@ private:
     LogLevel m_logLevel;
     bool m_logReq;
     bool m_logResp;
+    LogLevel txSummaryLevel;
+    bool txSummaryResourceReq;
     unsigned m_slowProcessingTime;
     StringAttr m_frameTitle;
     Mutex abortMutex;
@@ -76,6 +78,8 @@ public:
         m_logLevel = config->m_options.logLevel;
         m_logReq = config->m_options.logReq;
         m_logResp = config->m_options.logResp;
+        txSummaryLevel = config->m_options.txSummaryLevel;
+        txSummaryResourceReq = config->m_options.txSummaryResourceReq;
         m_slowProcessingTime = config->m_options.slowProcessingTime;
         m_frameTitle.set(config->m_options.frameTitle);
         m_SEHMappingEnabled = false;
@@ -145,10 +149,14 @@ public:
     void setLogLevel(LogLevel level) { m_logLevel = level; }
     void setLogRequests(bool logReq) { m_logReq = logReq; }
     void setLogResponses(bool logResp) { m_logResp = logResp; }
+    void setTxSummaryLevel(LogLevel level) { txSummaryLevel = level; }
+    void setTxSummaryResourceReq(bool logReq) { txSummaryResourceReq = logReq; }
 
     LogLevel getLogLevel() { return m_logLevel; }
     bool getLogRequests() { return m_logReq; }
     bool getLogResponses() { return m_logResp; }
+    LogLevel getTxSummaryLevel() { return txSummaryLevel; }
+    bool getTxSummaryResourceReq() { return txSummaryResourceReq; }
     void setFrameTitle(const char* title)  { m_frameTitle.set(title); }
     const char* getFrameTitle()  { return m_frameTitle.get(); }
     unsigned getSlowProcessingTime() { return m_slowProcessingTime; }

esp/scm/esp.ecm

@@ -150,11 +150,12 @@ interface IEspContext : extends IInterface
     virtual void addCustomerHeader(const char* name, const char* val) = 0;
 
     virtual CTxSummary* queryTxSummary()=0;
-    virtual void addTraceSummaryValue(const char *name, const char *value)=0;
-    virtual void addTraceSummaryValue(const char *name, __int64 value)=0;
-    virtual void addTraceSummaryTimeStamp(const char *name)=0;
-    virtual void addTraceSummaryCumulativeTime(const char* name, unsigned __int64 time)=0;
+    virtual void addTraceSummaryValue(unsigned logLevel, const char *name, const char *value)=0;
+    virtual void addTraceSummaryValue(unsigned logLevel, const char *name, __int64 value)=0;
+    virtual void addTraceSummaryTimeStamp(unsigned logLevel, const char *name)=0;
+    virtual void addTraceSummaryCumulativeTime(unsigned logLevel, const char* name, unsigned __int64 time)=0;
     virtual CumulativeTimer* queryTraceSummaryCumulativeTimer(const char* name)=0;
+    virtual void cancelTxSummary()=0;
 
     virtual ESPSerializationFormat getResponseFormat()=0;
     virtual void setResponseFormat(ESPSerializationFormat fmt)=0;
@@ -186,6 +187,10 @@ interface IEspContainer : extends IInterface
     virtual void setLogRequests(bool logReq) = 0;
     virtual bool getLogResponses() = 0;
     virtual void setLogResponses(bool logResp) = 0;
+    virtual void setTxSummaryLevel(LogLevel level) = 0;
+    virtual LogLevel getTxSummaryLevel() = 0;
+    virtual bool getTxSummaryResourceReq() = 0;
+    virtual void setTxSummaryResourceReq(bool req) = 0;
     virtual void log(LogLevel level, const char*,...) __attribute__((format(printf, 3, 4))) = 0;
     virtual unsigned getSlowProcessingTime() = 0;
     virtual void setFrameTitle(const char* title) = 0;

esp/services/esdl_svc_engine/esdl_binding.cpp

@@ -527,7 +527,7 @@ void EsdlServiceImpl::handleServiceRequest(IEspContext &context,
                                            unsigned int flags)
 {
     const char *mthName = mthdef.queryName();
-    context.addTraceSummaryValue("method", mthName);
+    context.addTraceSummaryValue(LogMin, "method", mthName);
 
     StringBuffer trxid;
     if (!m_bGenerateLocalTrxId)
@@ -954,9 +954,9 @@ void EsdlServiceImpl::sendTargetSOAP(IEspContext & context,
     ESPLOG(LogMax,"OUTGOING Request: %s", clreq.str());
     {
         EspTimeSection timing("Calling out to query");
-        context.addTraceSummaryTimeStamp("startcall");
+        context.addTraceSummaryTimeStamp(LogMin, "startcall");
         httpclient->sendRequest("POST", "text/xml", clreq, resp, status,true);
-        context.addTraceSummaryTimeStamp("endcall");
+        context.addTraceSummaryTimeStamp(LogMin, "endcall");
     }
 
     if (status.length()==0)
@@ -1361,7 +1361,7 @@ int EsdlBindingImpl::onGetInstantQuery(IEspContext &context,
                     response->send();
 
                     unsigned timetaken = msTick() - context.queryCreationTime();
-                    context.addTraceSummaryTimeStamp("respSent");
+                    context.addTraceSummaryTimeStamp(LogMin, "respSent");
 
                      m_pESDLService->esdl_log(context, *srvdef, *mthdef, tgtcfg.get(), tgtctx.get(), req_pt.get(), out.str(), logdata.str(), timetaken);
 
@@ -1621,7 +1621,7 @@ int EsdlBindingImpl::HandleSoapRequest(CHttpRequest* request,
             response->send();
 
             unsigned timetaken = msTick() - ctx->queryCreationTime();
-            ctx->addTraceSummaryTimeStamp("respSent");
+            ctx->addTraceSummaryTimeStamp(LogMin, "respSent");
 
              m_pESDLService->esdl_log(*ctx, *srvdef, *mthdef, tgtcfg.get(), tgtctx.get(), pt, baseout.str(), logdata.str(), timetaken);
 
@@ -2141,7 +2141,7 @@ int EsdlBindingImpl::getJsonTestForm(IEspContext &context, CHttpRequest* request
 void EsdlBindingImpl::handleJSONPost(CHttpRequest *request, CHttpResponse *response)
 {
     IEspContext *ctx = request->queryContext();
-    ctx->addTraceSummaryValue("Esdl Binding", "JSONPost");
+    ctx->addTraceSummaryValue(LogNormal, "Esdl Binding", "JSONPost");
 
     StringBuffer jsonresp;
 

esp/services/ws_ecl/ws_ecl_service.cpp

@@ -2439,7 +2439,7 @@ int CWsEclBinding::onGet(CHttpRequest* request, CHttpResponse* response)
         }
         else if (!stricmp(methodName.str(), "proxy"))
         {
-            context->addTraceSummaryValue("wseclMode", "proxy");
+            context->addTraceSummaryValue(LogMin, "wseclMode", "proxy");
 
             StringBuffer wuid;
             StringBuffer target;
@@ -2490,7 +2490,7 @@ int CWsEclBinding::onGet(CHttpRequest* request, CHttpResponse* response)
         }
         else if (!stricmp(methodName.str(), "submit"))
         {
-            context->addTraceSummaryValue("wseclMode", "submit");
+            context->addTraceSummaryValue(LogMin, "wseclMode", "submit");
 
             StringBuffer wuid;
             StringBuffer qs;
@@ -2507,7 +2507,7 @@ int CWsEclBinding::onGet(CHttpRequest* request, CHttpResponse* response)
         }
         else if (!stricmp(methodName.str(), "xslt"))
         {
-            context->addTraceSummaryValue("wseclMode", "xslt");
+            context->addTraceSummaryValue(LogMin, "wseclMode", "xslt");
 
             StringBuffer wuid;
             StringBuffer qs;
@@ -2602,7 +2602,7 @@ void checkForXmlResponseName(StartTag &starttag, StringBuffer &respname, int &so
 void CWsEclBinding::handleJSONPost(CHttpRequest *request, CHttpResponse *response)
 {
     IEspContext *ctx = request->queryContext();
-    ctx->addTraceSummaryValue("wseclMode", "JSONPost");
+    ctx->addTraceSummaryValue(LogMin, "wseclMode", "JSONPost");
     IProperties *parms = request->queryParameters();
     StringBuffer jsonresp;
 
@@ -2710,7 +2710,7 @@ void CWsEclBinding::handleHttpPost(CHttpRequest *request, CHttpResponse *respons
 int CWsEclBinding::HandleSoapRequest(CHttpRequest* request, CHttpResponse* response)
 {
     IEspContext *ctx = request->queryContext();
-    ctx->addTraceSummaryValue("wseclMode", "SOAPPost");
+    ctx->addTraceSummaryValue(LogMin, "wseclMode", "SOAPPost");
     IProperties *parms = request->queryParameters();
 
     const char *thepath = request->queryPath();

esp/services/ws_loggingservice/loggingservice.cpp

@@ -85,7 +85,7 @@ bool CWsLoggingServiceEx::onUpdateLog(IEspContext& context, IEspUpdateLogRequest
         if (!context.validateFeatureAccess(WSLOGGING_ACCESS, SecAccess_Write, false))
             throw MakeStringException(EspLoggingErrors::WSLoggingAccessDenied, "Failed to update log. Permission denied.");
 
-        context.addTraceSummaryTimeStamp("startQLog");
+        context.addTraceSummaryTimeStamp(LogMin, "startQLog");
         for (unsigned int x = 0; x < loggingAgentThreads.size(); x++)
         {
             IUpdateLogThread* loggingThread = loggingAgentThreads[x];
@@ -93,7 +93,7 @@ bool CWsLoggingServiceEx::onUpdateLog(IEspContext& context, IEspUpdateLogRequest
                 continue;
             loggingThread->queueLog(&req);
         }
-        context.addTraceSummaryTimeStamp("endQLog");
+        context.addTraceSummaryTimeStamp(LogMin, "endQLog");
         resp.setStatusCode(0);
         resp.setStatusMessage("Log will be updated.");
     }

initfiles/componentfiles/configxml/esp.xsd.in

@@ -776,6 +776,20 @@
             </xs:attribute>
             <xs:attribute name="logRequests" type="xs:boolean" use="optional" default="true"/>
             <xs:attribute name="logResponses" type="xs:boolean" use="optional" default="false"/>
+            <xs:attribute name="txSummaryLevel" type="xs:nonNegativeInteger" use="optional" default="1">
+                <xs:annotation>
+                    <xs:appinfo>
+                        <tooltip>Sets the TxSummary level [0: none, 1: min, 5: noraml, 10: max]</tooltip>
+                    </xs:appinfo>
+                </xs:annotation>
+            </xs:attribute>
+            <xs:attribute name="txSummaryResourceReq" type="xs:boolean" use="optional" default="false">
+                <xs:annotation>
+                    <xs:appinfo>
+                        <tooltip>Log TxSummary for Resource Requests</tooltip>
+                    </xs:appinfo>
+                </xs:annotation>
+            </xs:attribute>
         </xs:complexType>
     </xs:element>
 </xs:schema>

initfiles/etc/DIR_NAME/environment.xml.in

@@ -255,6 +255,8 @@
               logLevel="1"
               logRequests="false"
               logResponses="false"
+              txSummaryLevel="1"
+              txSummaryResourceReq="false"
               maxBacklogQueueSize="200"
               maxConcurrentThreads="0"
               maxRequestEntityLength="8000000"

testing/regress/environment.xml.in

@@ -255,6 +255,8 @@
               logLevel="1"
               logRequests="false"
               logResponses="false"
+              txSummaryLevel="1"
+              txSummaryResourceReq="false"
               maxBacklogQueueSize="200"
               maxConcurrentThreads="0"
               maxRequestEntityLength="8000000"