HPCC-14939 Encapsulate TxSummary logging in a new interface

- Change IEspTxSummary from .ecm-based interface to stand-alone CTxSummary
- Add TokenSerializer to convert templated types to StringBuffer using a now
  global operator <<, which in turn uses StringBuffer::append.
- Simplify CTxSummary interface
- Clean up CEspContext constructor member initialization

Signed-off-by: Tim Klemm <Tim.Klemm@lexisnexis.com>

esp/bindings/SOAP/soaplib/CMakeLists.txt

@@ -30,6 +30,7 @@ set (    SRCS
          ../../../platform/espprotocol.cpp 
          ../../../platform/espthread.cpp 
          ../../../platform/sechandler.cpp 
+         ../../../platform/txsummary.cpp
          ../../../protocols/http/mapinfo.cpp 
          ../../bindutil.cpp 
          ../../http/client/httpclient.cpp 

esp/platform/espcontext.cpp

@@ -25,6 +25,7 @@
 
 #include "jliball.hpp"
 #include "espcontext.hpp"
+#include "txsummary.hpp"
 #include "http/platform/httptransport.ipp"
 #include "sechandler.hpp"
 #include "espprotocol.hpp"
@@ -67,7 +68,7 @@ private:
     SecHandler m_SecurityHandler;
     BoolHash  m_optGroups;
 
-    StringArray m_traceValues;
+    Owned<CTxSummary> m_txSummary;
     unsigned    m_active;
     unsigned    m_creationTime;
     unsigned    m_processingTime;
@@ -80,12 +81,23 @@ private:
 public:
     IMPLEMENT_IINTERFACE;
 
-    CEspContext() : m_servPort(0), m_bindingValue(0), m_serviceValue(0), m_toBeAuthenticated(false), options(0), m_clientVer(-1)
-    {
-        m_hasException =  false;
-        m_creationTime = msTick();
-        m_active=ActiveRequests::getCount();
-        respSerializationFormat=ESPSerializationANY;
+    CEspContext()
+    : m_servPort(0)
+    , m_bindingValue(0)
+    , m_serviceValue(0)
+    , m_toBeAuthenticated(false)
+    , m_clientVer(-1)
+    , options(0)
+    , m_active(ActiveRequests::getCount())
+    , m_creationTime(msTick())
+    , m_processingTime(0)
+    , m_exceptionTime(0)
+    , m_hasException(false)
+    , m_exceptionCode(0)
+    , respSerializationFormat(ESPSerializationANY)
+    {
+        m_txSummary.setown(new CTxSummary(m_creationTime));
+        updateTraceSummaryHeader();
     }
 
     ~CEspContext()
@@ -187,10 +199,6 @@ public:
         return m_servName.str();
     }
 
-    virtual void setCreationTime()
-    {
-        m_creationTime = msTick();
-    }
     virtual const unsigned queryCreationTime()
     {
         return m_creationTime;
@@ -408,72 +416,44 @@ public:
         m_custom_headers.append(StringBuffer(name).appendf(": %s", val?val:"").str());
     }
 
+    virtual CTxSummary* getTxSummary()
+    {
+        return m_txSummary.get();
+    }
+
     virtual void addTraceSummaryValue(const char *name, const char *value)
     {
-        StringBuffer str;
-        if (name && *name)
-            str.append(name).append('=');
-        if (value && *value)
-            str.append(value);
-        m_traceValues.append(str.str());
+        if (m_txSummary)
+            m_txSummary->append(name, value);
     }
 
     virtual void addTraceSummaryValue(const char *name, __int64 value)
     {
-        StringBuffer str;
-        if (name && *name)
-            str.append(name).append('=');
-        str.append(value);
-        m_traceValues.append(str.str());
+        if (m_txSummary)
+            m_txSummary->append(name, value);
     }
 
     virtual void addTraceSummaryTimeStamp(const char *name)
     {
-        if (name && *name)
-        {
-            unsigned timeval=msTick()-m_creationTime;
-            StringBuffer value;
-            value.append(name).append('=').appendulong(timeval).append("ms");
-            m_traceValues.append(value.str());
-        }
+        if (m_txSummary && name && *name)
+            m_txSummary->append(name, m_txSummary->getElapsedTime(), "ms");
     }
     virtual void flushTraceSummary()
     {
-        StringBuffer logstr;
-        logstr.appendf("activeReqs=").append(m_active).append(';');
-        logstr.append("user=").append(queryUserId());
-        if (m_peer.length())
-            logstr.append('@').append(m_peer.get());
-        logstr.append(';');
-
-        if (m_hasException)
-        {
-            logstr.appendf("exception@%dms=%d;", m_exceptionTime, m_exceptionCode);
-        }
-
-        StringBuffer value;
-        value.append("total=").appendulong(m_processingTime).append("ms");
-        if (m_hasException || (getEspLogLevel() > LogNormal))
+        if (m_txSummary)
         {
-            m_traceValues.append(value.str());
+            if (!m_hasException && (getEspLogLevel() <= LogNormal))
+                m_txSummary->clear();
 
-            if (m_traceValues.length())
-            {
-                ForEachItemIn(idx, m_traceValues)
-                    logstr.append(m_traceValues.item(idx)).append(";");
-                m_traceValues.kill();
-            }
-        }
-        else
-        {
-            logstr.appendf("%s;", value.str());
+            updateTraceSummaryHeader();
+            m_txSummary->append("total", m_processingTime, "ms");
         }
-
-        DBGLOG("TxSummary[%s]", logstr.str());
     }
 
     virtual ESPSerializationFormat getResponseFormat(){return respSerializationFormat;}
     virtual void setResponseFormat(ESPSerializationFormat fmt){respSerializationFormat = fmt;}
+
+    void updateTraceSummaryHeader();
 };
 
 //---------------------------------------------------------
@@ -555,6 +535,17 @@ bool CEspContext::isMethodAllowed(double version, const char* optional, const ch
     return true;
 }
 
+void CEspContext::updateTraceSummaryHeader()
+{
+    if (m_txSummary)
+    {
+        m_txSummary->set("activeReqs", m_active);
+        m_txSummary->set("user", VStringBuffer("%s%s%s", (queryUserId() ? queryUserId() : ""), (m_peer.length() ? "@" : ""), m_peer.str()).str());
+        if (m_hasException)
+            m_txSummary->set(VStringBuffer("exception@%ums", m_exceptionTime), m_exceptionCode);
+    }
+}
+
 IEspContext* createEspContext()
 {
     return new CEspContext;

esp/platform/tokenserialization.hpp

@@ -0,0 +1,54 @@
+/*##############################################################################
+
+    HPCC SYSTEMS software Copyright (C) 2016 HPCC Systems®.
+
+    Licensed under the Apache License, Version 2.0 (the "License");
+    you may not use this file except in compliance with the License.
+    You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+    Unless required by applicable law or agreed to in writing, software
+    distributed under the License is distributed on an "AS IS" BASIS,
+    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+    See the License for the specific language governing permissions and
+    limitations under the License.
+############################################################################## */
+
+#ifndef TOKENSERIALIZATION_HPP
+#define TOKENSERIALIZATION_HPP
+
+#include "jstring.hpp"
+
+class TokenSerializer
+{
+public:
+    // Produce a buffer suitable for use by the serialize method. Used by
+    // template methods that do not inherently know the buffer type.
+    StringBuffer makeBuffer() const
+    {
+        return StringBuffer();
+    }
+
+    // Write any type of data to a given text buffer. There must be an
+    // overloaded operator << to insert the value type into the buffer type.
+    //
+    // While this does allow multiple tokens to be serialized into a buffer,
+    // it is the caller's responsibility to add any delimiters necessary for
+    // subsequent deserialization.
+    template <typename TValue>
+    StringBuffer& serialize(const TValue& value, StringBuffer& buffer) const
+    {
+        buffer << value;
+        return buffer;
+    }
+
+    // Convert a buffer to a character array. Used by template methods that do
+    // not inherently know the buffer type.
+    const char* str(const StringBuffer& buffer) const
+    {
+        return buffer.str();
+    }
+};
+
+#endif // TOKENSERIALIZATION_HPP

esp/platform/txsummary.cpp

@@ -0,0 +1,103 @@
+/*##############################################################################
+
+    HPCC SYSTEMS software Copyright (C) 2016 HPCC Systems®.
+
+    Licensed under the Apache License, Version 2.0 (the "License");
+    you may not use this file except in compliance with the License.
+    You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+    Unless required by applicable law or agreed to in writing, software
+    distributed under the License is distributed on an "AS IS" BASIS,
+    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+    See the License for the specific language governing permissions and
+    limitations under the License.
+############################################################################## */
+
+#include "txsummary.hpp"
+#include "jlog.hpp"
+#include "jutil.hpp"
+#include <algorithm>
+
+using std::find_if;
+
+#define VALIDATE_KEY(k) if (!(k) || !(*k)) return false
+#define MATCH_KEY       [&](const Entry& entry) { return stricmp(entry.key.str(), key) == 0; }
+
+CTxSummary::CTxSummary(unsigned creationTime)
+: m_creationTime(creationTime ? creationTime : msTick())
+{
+}
+
+CTxSummary::~CTxSummary()
+{
+    log();
+    clear();
+}
+
+unsigned __int64 CTxSummary::size() const
+{
+    return m_entries.size();
+}
+
+void CTxSummary::clear()
+{
+    m_entries.clear();
+}
+
+unsigned CTxSummary::getElapsedTime() const
+{
+    return msTick() - m_creationTime;
+}
+
+bool CTxSummary::contains(const char* key) const
+{
+    return find_if(m_entries.begin(), m_entries.end(), MATCH_KEY) != m_entries.end();
+}
+
+bool CTxSummary::append(const char* key, const char* value)
+{
+    VALIDATE_KEY(key);
+
+    if (contains(key))
+        return false;
+
+    m_entries.push_back({key, value});
+    return true;
+}
+
+bool CTxSummary::set(const char* key, const char* value)
+{
+    VALIDATE_KEY(key);
+
+    Entries::iterator it = find_if(m_entries.begin(), m_entries.end(), MATCH_KEY);
+
+    if (it != m_entries.end())
+        it->value.set(value);
+    else
+        m_entries.push_back({key, value});
+
+    return true;
+}
+
+void CTxSummary::serialize(StringBuffer& buffer) const
+{
+    for (const Entry& entry : m_entries)
+    {
+        if (entry.value.length())
+            buffer.appendf("%s=%s;", entry.key.str(), entry.value.str());
+        else
+            buffer.appendf("%s;", entry.key.str());
+    }
+}
+
+void CTxSummary::log()
+{
+    if (size())
+    {
+        StringBuffer summary;
+        serialize(summary);
+        DBGLOG("TxSummary[%s]", summary.str());
+    }
+}

esp/platform/txsummary.hpp

@@ -0,0 +1,107 @@
+/*##############################################################################
+
+    HPCC SYSTEMS software Copyright (C) 2016 HPCC Systems®.
+
+    Licensed under the Apache License, Version 2.0 (the "License");
+    you may not use this file except in compliance with the License.
+    You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+    Unless required by applicable law or agreed to in writing, software
+    distributed under the License is distributed on an "AS IS" BASIS,
+    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+    See the License for the specific language governing permissions and
+    limitations under the License.
+############################################################################## */
+
+#ifndef TXSUMMARY_HPP
+#define TXSUMMARY_HPP
+
+#include "jiface.hpp"
+#include "tokenserialization.hpp"
+#include "esphttp.hpp"
+#include <list>
+
+class CTxSummary : extends CInterface
+{
+public:
+    IMPLEMENT_IINTERFACE;
+    
+    // Construct an instance with the given creation time. A non-zero value
+    // allows the summary to be in sync with its owning object. A value of
+    // zero causes the summary to base its elapsed time calculations on its
+    // own construction time.
+    CTxSummary(unsigned creationTime = 0);
+
+    // Returns the number of summary entries.
+    virtual unsigned __int64 size() const;
+
+    // Purges all summary entries.
+    virtual void clear();
+
+    // Returns true if an entry exists for the key.
+    virtual bool contains(const char* key) const;
+
+    // Returns the number of milliseconds elapsed since the construction of
+    // the summary.
+    virtual unsigned getElapsedTime() const;
+
+    // Appends all summary entries to the given buffer.
+    virtual void serialize(StringBuffer& buffer) const;
+
+    // Adds the unique key and value to the end of the summary.
+    // Returns true if the key value pair are added to the summary. Returns
+    // false if the key is NULL, empty, or not unique within the summary.
+    virtual bool append(const char* key, const char* value);
+    template <typename TValue, typename TSuffix = const char*, class TSerializer = TokenSerializer>
+    bool append(const char* key, const TValue& value, const TSuffix& suffix = "", const TSerializer& serializer = TSerializer());
+
+    // Updates the value associated with an existing key, or appends the key
+    // and value to the summary if it is not already found. Returns false if
+    // the key is NULL or empty. Returns true otherwise.
+    virtual bool set(const char* key, const char* value);
+    template <typename TValue, typename TSuffix = const char*, class TSerializer = TokenSerializer>
+    bool set(const char* key, const TValue& value, const TSuffix& suffix = "", const TSerializer& serializer = TSerializer());
+
+protected:
+    // Log the summary contents on destruction.
+    ~CTxSummary();
+
+private:
+    void log();
+
+    struct Entry
+    {
+        StringBuffer key;
+        StringBuffer value;
+    };
+
+    using Entries = std::list<Entry>;
+
+    Entries   m_entries;
+    unsigned  m_creationTime;
+};
+
+
+// Convenience wrapper of the default append method.
+template <typename TValue, typename TSuffix, class TSerializer>
+inline bool CTxSummary::append(const char* key, const TValue& value, const TSuffix& suffix, const TSerializer& serializer)
+{
+    auto buffer = serializer.makeBuffer();
+    serializer.serialize(value, buffer);
+    serializer.serialize(suffix, buffer);
+    return append(key, serializer.str(buffer));
+}
+
+// Convenience wrapper of the default set method.
+template <typename TValue, typename TSuffix, class TSerializer>
+inline bool CTxSummary::set(const char* key, const TValue& value, const TSuffix& suffix, const TSerializer& serializer)
+{
+    auto buffer = serializer.makeBuffer();
+    serializer.serialize(value, buffer);
+    serializer.serialize(suffix, buffer);
+    return set(key, serializer.str(buffer));
+}
+
+#endif // TXSUMMARY_HPP

esp/protocols/http/CMakeLists.txt

@@ -45,6 +45,7 @@ set (    SRCS
          ../../platform/espprotocol.cpp 
          ../../platform/espthread.cpp 
          ../../platform/sechandler.cpp 
+         ../../platform/txsummary.cpp
          mapinfo.cpp 
          plugin.cpp 
     )

esp/scm/esp.ecm

@@ -60,6 +60,8 @@ typedef enum ESPSerializationFormat_
 #define ESPCTX_NO_ANNOTATION    0x00001000
 #define ESPCTX_ALL_ANNOTATION   0x00010000
 
+class CTxSummary;
+
 interface IEspContext : extends IInterface
 {
     virtual void setUserID(const char * userid) = 0;
@@ -109,7 +111,6 @@ interface IEspContext : extends IInterface
 
     virtual void setServiceName(const char *name)=0;
     virtual const char * queryServiceName(const char *name)=0;
-    virtual void setCreationTime()=0;
     virtual const unsigned queryCreationTime()=0;
     virtual void setProcessingTime()=0;
     virtual const unsigned queryProcessingTime()=0;
@@ -144,10 +145,10 @@ interface IEspContext : extends IInterface
     virtual StringArray& queryCustomHeaders() = 0;
     virtual void addCustomerHeader(const char* name, const char* val) = 0;
 
+    virtual CTxSummary* getTxSummary()=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 flushTraceSummary()=0;
 
     virtual ESPSerializationFormat getResponseFormat()=0;
     virtual void setResponseFormat(ESPSerializationFormat fmt)=0;

esp/services/common/wshelpers.hpp

@@ -23,8 +23,6 @@
 #ifndef _ESPWIZ_WSHELPERS_HPP__
 #define _ESPWIZ_WSHELPERS_HPP__
 
-template<typename T> inline StringBuffer& operator<<(StringBuffer& buf, const T& t) { return buf.append(t); }
-
 static StringBuffer &buildComma(StringBuffer &s, unsigned __int64 val)
 {
     if (val)

system/jlib/jstring.hpp

@@ -540,6 +540,12 @@ inline StringBuffer &appendJSONValue(StringBuffer& s, const char *name, unsigned
     return s.appendulong(value);
 }
 
+template <typename TValue>
+inline StringBuffer& operator << (StringBuffer& s, const TValue& value)
+{
+    return s.append(value);
+}
+
 extern jlib_decl void decodeCppEscapeSequence(StringBuffer & out, const char * in, bool errorIfInvalid);
 extern jlib_decl bool strToBool(const char * text);
 extern jlib_decl bool strToBool(size_t len, const char * text);