Improved debug tag performance
authorEriks Jenkevics <eriks@netxms.org>
Wed, 20 Sep 2017 13:41:47 +0000 (16:41 +0300)
committerEriks Jenkevics <eriks@netxms.org>
Wed, 20 Sep 2017 13:41:53 +0000 (16:41 +0300)
include/nms_util.h
include/nxatomic.h
src/db/libnxdb/session.cpp
src/libnetxms/debug_tag_tree.cpp
src/libnetxms/debug_tag_tree.h
src/libnetxms/log.cpp
src/libnetxms/strmapbase.cpp
src/server/core/console.cpp
tests/test-libnetxms/test-libnetxms.cpp

index bc2c2d3..d44c5dd 100644 (file)
@@ -867,9 +867,10 @@ protected:
    bool m_ignoreCase;
        void (*m_objectDestructor)(void *);
 
-       StringMapEntry *find(const TCHAR *key) const;
+       StringMapEntry *find(const TCHAR *key, int keyLen) const;
        void setObject(TCHAR *key, void *value, bool keyPreAlloc);
        void *getObject(const TCHAR *key) const;
+   void *getObject(const TCHAR *key, size_t len) const;
        void destroyObject(void *object) { if (object != NULL) m_objectDestructor(object); }
 
 public:
@@ -884,7 +885,8 @@ public:
    void filterElements(bool (*filter)(const TCHAR *, const void *, void *), void *userData);
 
        int size() const;
-   bool contains(const TCHAR *key) const { return find(key) != NULL; }
+   bool contains(const TCHAR *key) const { return (key != NULL) ? (find(key, (int)_tcslen(key) * sizeof(TCHAR)) != NULL) : false; }
+   bool contains(const TCHAR *key, size_t len) const { return (key != NULL) ? (find(key, (int)len * sizeof(TCHAR)) != NULL) : false; }
 
    EnumerationCallbackResult forEach(EnumerationCallbackResult (*cb)(const TCHAR *, const void *, void *), void *userData) const;
    const void *findElement(bool (*comparator)(const TCHAR *, const void *, void *), void *userData) const;
@@ -917,6 +919,7 @@ public:
    void addAll(const StringMap *src);
 
        const TCHAR *get(const TCHAR *key) const { return (const TCHAR *)getObject(key); }
+   const TCHAR *get(const TCHAR *key, size_t len) const { return (const TCHAR *)getObject(key, len); }
    INT32 getInt32(const TCHAR *key, INT32 defaultValue) const;
        UINT32 getUInt32(const TCHAR *key, UINT32 defaultValue) const;
    INT64 getInt64(const TCHAR *key, INT64 defaultValue) const;
@@ -944,6 +947,7 @@ public:
        void set(const TCHAR *key, T *object) { setObject((TCHAR *)key, (void *)object, false); }
        void setPreallocated(TCHAR *key, T *object) { setObject((TCHAR *)key, (void *)object, true); }
        T *get(const TCHAR *key) const { return (T*)getObject(key); }
+   T *get(const TCHAR *key, size_t len) const { return (T*)getObject(key, len); }
 };
 
 /**
index 6681d43..58af18e 100644 (file)
@@ -228,7 +228,7 @@ inline VolatileCounter InterlockedDecrement(VolatileCounter *v)
 /**
  * Atomically set pointer
  */
-inline void *InterlockedExchangePointer(void *volatile *target, void *value)
+inline void *InterlockedExchangePointer(voidvolatile *target, void *value)
 {
 #if defined(__GNUC__) && ((__GNUC__ < 4) || (__GNUC_MINOR__ < 1)) && (defined(__i386__) || defined(__x86_64__))
    void *oldval;
@@ -248,4 +248,16 @@ inline void *InterlockedExchangePointer(void *volatile *target, void *value)
 
 #endif   /* _WIN32 */
 
+#ifdef __cplusplus
+
+/**
+ * Atomically set pointer
+ */
+template<typename T> T *InterlockedExchangePointer(T* volatile *target, T *value)
+{
+   return static_cast<T*>(InterlockedExchangePointer(reinterpret_cast<void* volatile *>(target), value));
+}
+
+#endif   /* __cplusplus */
+
 #endif
index 243edca..3a7211f 100644 (file)
@@ -172,7 +172,7 @@ static void DBReconnect(DB_HANDLE hConn)
    int nCount;
        WCHAR errorText[DBDRV_MAX_ERROR_TEXT];
 
-   nxlog_debug_tag(_T("db.connection"), 4, _T("DB reconnect: handle=%p"), hConn);
+   nxlog_debug_tag(_T("db.connect"), 4, _T("DB reconnect: handle=%p"), hConn);
 
    InvalidatePreparedStatements(hConn);
        hConn->m_driver->m_fpDrvDisconnect(hConn->m_connection);
index d7bb833..2a147fe 100644 (file)
 #include "debug_tag_tree.h"
 
 /**
+ * Create empty tree node
+ */
+DebugTagTreeNode::DebugTagTreeNode()
+{
+   m_value = NULL;
+   m_direct = false;
+   m_directLvL = 0;
+   m_asterisk = false;
+   m_asteriskLvL = 0;
+   m_children = new StringObjectMap<DebugTagTreeNode>(true);
+}
+
+/**
  * Create new tree node
  */
-DebugTagTreeNode::DebugTagTreeNode(const TCHAR *value)
+DebugTagTreeNode::DebugTagTreeNode(const TCHAR *value, size_t len)
 {
-   m_value = new String(value);
+   m_value = (TCHAR *)malloc(sizeof(TCHAR) * ((int)len + 1));
+   memcpy(m_value, value, sizeof(TCHAR) * (int)len);
+   m_value[len] = 0;
    m_direct = false;
    m_directLvL = 0;
    m_asterisk = false;
@@ -38,17 +53,26 @@ DebugTagTreeNode::DebugTagTreeNode(const TCHAR *value)
 /**
  * Get debug LvL from tree node, returns longest match (recursive)
  */
-int DebugTagTreeNode::getDebugLvl(const StringList *tags, UINT32 pos)
+int DebugTagTreeNode::getDebugLvl(const TCHAR *tags)
 {
-   if ((tags->size() == pos) && m_direct)
-      return m_directLvL;
+   if (tags == NULL)
+   {
+      if (m_direct)
+         return m_directLvL;
+      if (m_asterisk)
+         return m_asteriskLvL;
+      return -1;
+   }
 
    int result = -1;
-   DebugTagTreeNode *child = m_children->get(tags->get(pos));
+   const TCHAR *ptr = _tcschr(tags, _T('.'));
+   int len = (ptr == NULL) ? _tcslen(tags) : (ptr - tags);
+
+   DebugTagTreeNode *child = m_children->get(tags, len);
    if (child != NULL)
-      result = child->getDebugLvl(tags, pos+1);
+      result = child->getDebugLvl((ptr != NULL) ? ptr + 1 : NULL);
 
-   if (result == -1 && tags->size() > pos && m_asterisk)
+   if (result == -1 && m_asterisk)
       return m_asteriskLvL;
 
    return result;
@@ -57,55 +81,65 @@ int DebugTagTreeNode::getDebugLvl(const StringList *tags, UINT32 pos)
 /**
  * Add new tree node to its children and grand children etc... (recursive)
  */
-void DebugTagTreeNode::add(const StringList *tags, UINT32 pos, UINT32 lvl)
+void DebugTagTreeNode::add(const TCHAR *tags, UINT32 lvl)
 {
-   if (tags->size() == pos)
+   if (tags != NULL && !_tcscmp(tags, _T("*")))
+   {
+      if (!m_asterisk)
+         m_asterisk = true;
+      m_asteriskLvL = lvl;
+      return;
+   }
+
+   const TCHAR *ptr = (tags == NULL) ? NULL : _tcschr(tags, _T('.'));
+
+   if (tags == NULL)
    {
       if (!m_direct)
          m_direct = true;
       m_directLvL = lvl;
-
       return;
    }
 
-   DebugTagTreeNode *child = m_children->get(tags->get(pos));
+   int len = (ptr == NULL) ? _tcslen(tags) : (ptr - tags);
+
+   DebugTagTreeNode *child = m_children->get(tags, len);
    if (child != NULL)
-      child->add(tags, pos+1, lvl);
+      child->add((ptr != NULL) ? ptr + 1 : NULL, lvl);
    else
    {
-      if (tags->size() > pos && !_tcscmp(tags->get(pos), _T("*")))
-      {
-         if (!m_asterisk)
-            m_asterisk = true;
-         m_asteriskLvL = lvl;
-      }
-      else
-      {
-         child = new DebugTagTreeNode(tags->get(pos));
-         m_children->set(tags->get(pos), child);
-         child->add(tags, pos+1, lvl);
-      }
+      child = new DebugTagTreeNode(tags, len);
+      m_children->set(child->getValue(), child);
+      child->add((ptr != NULL) ? ptr + 1 : NULL, lvl);
    }
 }
 
 /**
  * Remove entry from child list (recursive)
  */
-bool DebugTagTreeNode::remove(const StringList *tags, UINT32 pos)
+bool DebugTagTreeNode::remove(const TCHAR *tags)
 {
-   DebugTagTreeNode *child = m_children->get(tags->get(pos));
-   if (child != NULL && child->remove(tags, pos+1))
-      m_children->remove(tags->get(pos));
+   const TCHAR *ptr = NULL;
+
+   if (tags != NULL)
+   {
+      ptr = _tcschr(tags, _T('.'));
+      int len = (ptr == NULL) ? _tcslen(tags) : (ptr - tags);
+
+      DebugTagTreeNode *child = m_children->get(tags, len);
+      if (child != NULL && child->remove((ptr != NULL) ? ptr + 1 : NULL))
+         m_children->remove(child->getValue());
+   }
 
-   if ((tags->size() == pos+1) && (!_tcscmp(tags->get(pos), _T("*"))))
+   if (tags != NULL && !_tcscmp(tags, _T("*")))
    {
       m_asterisk = false;
-      m_asteriskLvL = -1;
+      m_asteriskLvL = 0;
    }
-   else if ((tags->size() == pos) && m_direct)
+   else if (tags == NULL)
    {
       m_direct = false;
-      m_directLvL = -1;
+      m_directLvL = 0;
    }
 
    if ((m_children->size() == 0) && !m_asterisk)
@@ -117,19 +151,41 @@ bool DebugTagTreeNode::remove(const StringList *tags, UINT32 pos)
 /**
  * Get debug LvL from tree, returns longest match (recursive)
  */
-int DebugTagTree::getDebugLvl(const TCHAR *tags)
+UINT32 DebugTagTree::getDebugLvl(const TCHAR *tags)
 {
-   String s(tags);
-   StringList *tagList = s.split(_T("."));
-   if (tagList->size() == 0)
-      tagList->add(_T("*"));
+   InterlockedIncrement(&m_readerCount);
+   int result;
+   if (tags == NULL)
+       result = getRootDebugLvl();
+    else
+    {
+       result = m_root->getDebugLvl(tags);
+       if (result == -1)
+          result = 0;
+    }
+   InterlockedDecrement(&m_readerCount);
+   return result;
+}
 
-   int result = m_root->getDebugLvl(tagList, 0);
+/**
+ * Get main debug level
+ */
+UINT32 DebugTagTree::getRootDebugLvl()
+{
+   InterlockedIncrement(&m_readerCount);
+   UINT32 level = m_root->m_asteriskLvL;
+   InterlockedDecrement(&m_readerCount);
+   return level;
+}
 
-   delete(tagList);
-   if (result == -1)
-      return 0;
-   return result;
+/**
+ * Set debug lvl for root node
+ */
+void DebugTagTree::setRootDebugLvl(UINT32 lvl)
+{
+   m_root->m_asteriskLvL = lvl;
+   if (!m_root->m_asterisk)
+      m_root->m_asterisk = true;
 }
 
 /**
@@ -137,14 +193,10 @@ int DebugTagTree::getDebugLvl(const TCHAR *tags)
  */
 void DebugTagTree::add(const TCHAR *tags, UINT32 lvl)
 {
-   String s(tags);
-   StringList *tagList = s.split(_T("."));
-   if (tagList->size() == 0)
-      tagList->add(_T("*"));
-
-   m_root->add(tagList, 0, lvl);
-
-   delete(tagList);
+   if (tags == NULL)
+      setRootDebugLvl(lvl);
+   else
+      m_root->add(tags, lvl);
 }
 
 /**
@@ -152,10 +204,8 @@ void DebugTagTree::add(const TCHAR *tags, UINT32 lvl)
  */
 void DebugTagTree::remove(const TCHAR *tags)
 {
-   String s(tags);
-   StringList *tagList = s.split(_T("."));
-   if (tagList->size() == 0)
-      tagList->add(_T("*"));
-
-   m_root->remove(tagList, 0);
+   if (tags == NULL)
+       setRootDebugLvl(0);
+    else
+       m_root->remove(tags);
 }
index d2ebbb5..23de90e 100644 (file)
@@ -28,33 +28,41 @@ class DebugTagTreeNode
    friend class DebugTagTree;
 
 private:
-   String *m_value;
+   TCHAR *m_value;
    StringObjectMap<DebugTagTreeNode> *m_children;
    bool m_direct;
    bool m_asterisk;
-   int m_directLvL;
-   int m_asteriskLvL;
+   UINT32 m_directLvL;
+   UINT32 m_asteriskLvL;
 
-   DebugTagTreeNode(const TCHAR *value);
+   DebugTagTreeNode();
+   DebugTagTreeNode(const TCHAR *value, size_t len);
 
-   int getDebugLvl(const StringList *tags, UINT32 pos);
-   void add(const StringList *tags, UINT32 pos, UINT32 lvl);
-   bool remove(const StringList *tags, UINT32 pos);
+   int getDebugLvl(const TCHAR *tags);
+   const TCHAR *getValue() const { return m_value; }
+   void add(const TCHAR *tags, UINT32 lvl);
+   bool remove(const TCHAR *tags);
 
 public:
-   ~DebugTagTreeNode() { delete(m_value); delete(m_children); }
+   ~DebugTagTreeNode() { free(m_value); delete(m_children); }
 };
 
 class DebugTagTree
 {
 private:
    DebugTagTreeNode *m_root;
+   VolatileCounter m_readerCount;
 
 public:
-   DebugTagTree() { m_root = new DebugTagTreeNode(_T("")); }
+   DebugTagTree() { m_root = new DebugTagTreeNode(); m_readerCount = 0; }
    ~DebugTagTree() { delete(m_root); }
 
    void add(const TCHAR *tags, UINT32 lvl);
    void remove(const TCHAR *tags);
-   int getDebugLvl(const TCHAR *tags);
+   UINT32 getDebugLvl(const TCHAR *tags);
+
+   void setRootDebugLvl(UINT32 lvl);
+   UINT32 getRootDebugLvl();
+
+   INT32 getReaderCount() { return (INT32)m_readerCount; }
 };
index f66304d..0ed0c57 100644 (file)
@@ -59,18 +59,36 @@ static String s_logBuffer;
 static THREAD s_writerThread = INVALID_THREAD_HANDLE;
 static CONDITION s_writerStopCondition = INVALID_CONDITION_HANDLE;
 static NxLogDebugWriter s_debugWriter = NULL;
-static DebugTagTree tagTree;
-static MUTEX m_mutexDebugTagTreeAccess = INVALID_MUTEX_HANDLE;
+static DebugTagTree* volatile tagTreeActive = new DebugTagTree();
+static DebugTagTree* volatile tagTreeSecondary = new DebugTagTree();
+static MUTEX m_mutexDebugTagTreeWrite = INVALID_MUTEX_HANDLE;
+
+/**
+ * Swaps tag tree pointers and waits till reader count drops to 0
+ */
+static inline void swapAndWait()
+{
+   tagTreeSecondary = InterlockedExchangePointer(&tagTreeActive, tagTreeSecondary);
+   ThreadSleepMs(10);
+
+   // Wait for tree reader count to drop to 0
+   while(tagTreeSecondary->getReaderCount() > 0)
+      ThreadSleepMs(10);
+}
 
 /**
  * Set debug level
  */
 void LIBNETXMS_EXPORTABLE nxlog_set_debug_level(int level)
 {
-   MutexLock(m_mutexDebugTagTreeAccess);
    if ((level >= 0) && (level <= 9))
-      tagTree.add(_T("*"), level);
-   MutexUnlock(m_mutexDebugTagTreeAccess);
+   {
+      MutexLock(m_mutexDebugTagTreeWrite);
+      tagTreeSecondary->setRootDebugLvl(level); // Update the secondary tree
+      swapAndWait();
+      tagTreeSecondary->setRootDebugLvl(level); // Update the previously active tree
+      MutexUnlock(m_mutexDebugTagTreeWrite);
+   }
 }
 
 /**
@@ -80,12 +98,20 @@ void LIBNETXMS_EXPORTABLE nxlog_set_debug_level_tag(const TCHAR *tag, int level)
 {
    if (tag != NULL)
    {
-      MutexLock(m_mutexDebugTagTreeAccess);
+      MutexLock(m_mutexDebugTagTreeWrite);
       if((level >= 0) && (level <= 9))
-         tagTree.add(tag, level);
+      {
+         tagTreeSecondary->add(tag, level);
+         swapAndWait();
+         tagTreeSecondary->add(tag, level);
+      }
       else if (level < 0)
-         tagTree.remove(tag);
-      MutexUnlock(m_mutexDebugTagTreeAccess);
+      {
+         tagTreeSecondary->remove(tag);
+         swapAndWait();
+         tagTreeSecondary->remove(tag);
+      }
+      MutexUnlock(m_mutexDebugTagTreeWrite);
    }
 }
 
@@ -94,11 +120,7 @@ void LIBNETXMS_EXPORTABLE nxlog_set_debug_level_tag(const TCHAR *tag, int level)
  */
 int LIBNETXMS_EXPORTABLE nxlog_get_debug_level()
 {
-   int level;
-   MutexLock(m_mutexDebugTagTreeAccess);
-   level = tagTree.getDebugLvl(_T("*"));
-   MutexUnlock(m_mutexDebugTagTreeAccess);
-   return level;
+   return tagTreeActive->getRootDebugLvl();
 }
 
 /**
@@ -106,11 +128,7 @@ int LIBNETXMS_EXPORTABLE nxlog_get_debug_level()
  */
 int LIBNETXMS_EXPORTABLE nxlog_get_debug_level_tag(const TCHAR *tag)
 {
-   int level;
-   MutexLock(m_mutexDebugTagTreeAccess);
-   level = tagTree.getDebugLvl(tag);
-   MutexUnlock(m_mutexDebugTagTreeAccess);
-   return level;
+   return tagTreeActive->getDebugLvl(tag);
 }
 
 /**
@@ -450,7 +468,7 @@ bool LIBNETXMS_EXPORTABLE nxlog_open(const TCHAR *logName, UINT32 flags,
       }
 
       m_mutexLogAccess = MutexCreate();
-      m_mutexDebugTagTreeAccess = MutexCreate();
+      m_mutexDebugTagTreeWrite = MutexCreate();
                SetDayStart();
    }
        return (s_flags & NXLOG_IS_OPEN) ? true : false;
@@ -479,12 +497,13 @@ void LIBNETXMS_EXPORTABLE nxlog_close()
             ThreadJoin(s_writerThread);
             ConditionDestroy(s_writerStopCondition);
          }
+
          if (m_logFileHandle != NULL)
             fclose(m_logFileHandle);
          if (m_mutexLogAccess != INVALID_MUTEX_HANDLE)
             MutexDestroy(m_mutexLogAccess);
-         if (m_mutexDebugTagTreeAccess != INVALID_MUTEX_HANDLE)
-            MutexDestroy(m_mutexDebugTagTreeAccess);
+         if (m_mutexDebugTagTreeWrite != INVALID_MUTEX_HANDLE)
+            MutexDestroy(m_mutexDebugTagTreeWrite);
       }
           s_flags &= ~NXLOG_IS_OPEN;
    }
index 00310e4..6235508 100644 (file)
@@ -71,13 +71,12 @@ void StringMapBase::clear()
 /**
  * Find entry index by key
  */
-StringMapEntry *StringMapBase::find(const TCHAR *key) const
+StringMapEntry *StringMapBase::find(const TCHAR *key, int keyLen) const
 {
        if (key == NULL)
                return NULL;
 
    StringMapEntry *entry;
-   int keyLen = (int)(_tcslen(key) * sizeof(TCHAR));
    if (m_ignoreCase)
    {
 #if HAVE_ALLOCA
@@ -107,7 +106,7 @@ void StringMapBase::setObject(TCHAR *key, void *value, bool keyPreAllocated)
    if (key == NULL)
       return;
 
-       StringMapEntry *entry = find(key);
+       StringMapEntry *entry = find(key, (int)_tcslen(key) * sizeof(TCHAR));
        if (entry != NULL)
        {
                if (keyPreAllocated)
@@ -155,7 +154,20 @@ void StringMapBase::setObject(TCHAR *key, void *value, bool keyPreAllocated)
  */
 void *StringMapBase::getObject(const TCHAR *key) const
 {
-       StringMapEntry *entry = find(key);
+   if (key == NULL)
+      return NULL;
+       StringMapEntry *entry = find(key, (int)_tcslen(key) * sizeof(TCHAR));
+   return (entry != NULL) ? entry->value : NULL;
+}
+
+/**
+ * Get value by key
+ */
+void *StringMapBase::getObject(const TCHAR *key, size_t len) const
+{
+   if (key == NULL)
+      return NULL;
+   StringMapEntry *entry = find(key, (int)len * sizeof(TCHAR));
    return (entry != NULL) ? entry->value : NULL;
 }
 
@@ -164,12 +176,12 @@ void *StringMapBase::getObject(const TCHAR *key) const
  */
 void StringMapBase::remove(const TCHAR *key)
 {
-   StringMapEntry *entry = find(key);
+   StringMapEntry *entry = find(key, (int)_tcslen(key) * sizeof(TCHAR));
    if (entry != NULL)
    {
       HASH_DEL(m_data, entry);
       free(entry->key);
-      safe_free(entry->originalKey);
+      free(entry->originalKey);
                if (m_objectOwner)
          destroyObject(entry->value);
       free(entry);
index aaea979..0f6bdf2 100644 (file)
@@ -129,13 +129,21 @@ int ProcessConsoleCommand(const TCHAR *pszCmdLine, CONSOLE_CTX pCtx)
       else if (list->size() == 2)
          level = (int)_tcstol(list->get(1), &eptr, 0);
 
-      if ((*eptr == 0) && (level >= 0) && (level <= 9))
+      if ((*eptr == 0) && (level >= -1) && (level <= 9))
       {
          if (list->size() == 1)
+         {
             nxlog_set_debug_level(level);
+            ConsolePrintf(pCtx, (level == 0) ? _T("Debug mode turned off\n") : _T("Debug level set to %d\n"), level);
+         }
          else if (list->size() == 2)
-            nxlog_set_debug_level_tag(list->get(1), level);
-         ConsolePrintf(pCtx, (level == 0) ? _T("Debug mode turned off\n") : _T("Debug level set to %d\n"), level);
+         {
+            nxlog_set_debug_level_tag(list->get(0), level);
+            if (level == -1)
+               ConsolePrintf(pCtx,  _T("Debug tag <%s> removed\n"), list->get(0));
+            else
+               ConsolePrintf(pCtx,  _T("Debug level for tag <%s> set to %d\n"), list->get(0), level);
+         }
       }
       else if (IsCommand(_T("OFF"), szBuffer, 2))
       {
index daa2527..07f19fc 100644 (file)
@@ -120,6 +120,7 @@ static void TestStringMap()
       _sntprintf(key, 64, _T("key-%d"), i);
       m->set(key, _T("consectetur adipiscing elit"));
    }
+   _tprintf(_T("size: %d"), m->size());
    AssertEquals(m->size(), 10000);
    v = m->get(_T("key-42"));
    AssertNotNull(v);