This is an automated email from the ASF dual-hosted git repository.

tross pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-dispatch.git


The following commit(s) were added to refs/heads/master by this push:
     new e528b51  Added debug-dump backtrace for leaked objects in pooled 
memory. (#711)
e528b51 is described below

commit e528b51f7cbc63cbb04373213b351d29eeb8c976
Author: Ted Ross <tr...@apache.org>
AuthorDate: Mon Mar 30 08:59:46 2020 -0400

    Added debug-dump backtrace for leaked objects in pooled memory. (#711)
    
    DISPATCH-1611 - Added debug-dump backtrace for leaked objects in pooled 
memory.
    * Free the backtrace strings.
    * Added timestamp to the debug output for leaked objects.
    Co-authored-by: Ted Ross <tr...@apache.org>
---
 include/qpid/dispatch/alloc_pool.h |  1 +
 src/alloc_pool.c                   | 78 +++++++++++++++++++++++++++++++++-----
 src/log.c                          | 18 ++++++---
 src/log_private.h                  |  2 +
 4 files changed, 84 insertions(+), 15 deletions(-)

diff --git a/include/qpid/dispatch/alloc_pool.h 
b/include/qpid/dispatch/alloc_pool.h
index 14641da..e8722a5 100644
--- a/include/qpid/dispatch/alloc_pool.h
+++ b/include/qpid/dispatch/alloc_pool.h
@@ -66,6 +66,7 @@ typedef struct {
     qd_alloc_pool_t      *global_pool;
     sys_mutex_t          *lock;
     qd_alloc_pool_list_t  tpool_list;
+    void                 *debug;
     uint32_t              trailer;
 } qd_alloc_type_desc_t;
 
diff --git a/src/alloc_pool.c b/src/alloc_pool.c
index 8454141..6e9b314 100644
--- a/src/alloc_pool.c
+++ b/src/alloc_pool.c
@@ -28,6 +28,11 @@
 #include "entity_cache.h"
 #include "config.h"
 
+#ifdef QD_MEMORY_DEBUG
+#include <execinfo.h>
+#include "log_private.h"
+#endif
+
 const char *QD_ALLOCATOR_TYPE = "allocator";
 
 typedef struct qd_alloc_type_t          qd_alloc_type_t;
@@ -35,26 +40,38 @@ typedef struct qd_alloc_item_t          qd_alloc_item_t;
 typedef struct qd_alloc_chunk_t         qd_alloc_chunk_t;
 typedef struct qd_alloc_linked_stack_t  qd_alloc_linked_stack_t;
 
-struct qd_alloc_type_t {
-    DEQ_LINKS(qd_alloc_type_t);
-    qd_alloc_type_desc_t *desc;
-};
-
-DEQ_DECLARE(qd_alloc_type_t, qd_alloc_type_list_t);
-
 #define PATTERN_FRONT 0xdeadbeef
 #define PATTERN_BACK  0xbabecafe
+#define STACK_DEPTH   10
 
 struct qd_alloc_item_t {
     uintmax_t             sequence;  // uintmax_t ensures proper alignment of 
following data
 #ifdef QD_MEMORY_DEBUG
     qd_alloc_type_desc_t *desc;
+    DEQ_LINKS(qd_alloc_item_t);
+    void                 *backtrace[STACK_DEPTH];
+    int                   backtrace_size;
+    struct timeval        timestamp;
     uint32_t              header;
 #endif
 };
 
+#ifdef QD_MEMORY_DEBUG
+DEQ_DECLARE(qd_alloc_item_t, qd_alloc_item_list_t);
+#endif
+
+struct qd_alloc_type_t {
+    DEQ_LINKS(qd_alloc_type_t);
+    qd_alloc_type_desc_t *desc;
+#ifdef QD_MEMORY_DEBUG
+    qd_alloc_item_list_t  allocated;
+#endif
+};
+
+DEQ_DECLARE(qd_alloc_type_t, qd_alloc_type_list_t);
+
 //128 has been chosen because many CPUs arch use an
-//adiacent line prefetching optimization that load
+//adjacent line prefetching optimization that load
 //2*cache line bytes in batch
 #define CHUNK_SIZE 128/sizeof(void*)
 
@@ -234,6 +251,10 @@ static void qd_alloc_init(qd_alloc_type_desc_t *desc)
         qd_alloc_type_t *type_item = NEW(qd_alloc_type_t);
         DEQ_ITEM_INIT(type_item);
         type_item->desc = desc;
+        desc->debug = type_item;
+#ifdef QD_MEMORY_DEBUG
+        DEQ_INIT(type_item->allocated);
+#endif
         DEQ_INSERT_TAIL(type_list, type_item);
 
         desc->header  = PATTERN_FRONT;
@@ -280,6 +301,12 @@ void *qd_alloc(qd_alloc_type_desc_t *desc, qd_alloc_pool_t 
**tpool)
     if (item) {
 #ifdef QD_MEMORY_DEBUG
         item->desc   = desc;
+        item->backtrace_size = backtrace(item->backtrace, STACK_DEPTH);
+        gettimeofday(&item->timestamp, NULL);
+        qd_alloc_type_t *qtype = (qd_alloc_type_t*) desc->debug;
+        sys_mutex_lock(desc->lock);
+        DEQ_INSERT_TAIL(qtype->allocated, item);
+        sys_mutex_unlock(desc->lock);
         item->header = PATTERN_FRONT;
         *((uint32_t*) ((char*) &item[1] + desc->total_size))= PATTERN_BACK;
         QD_MEMORY_FILL(&item[1], QD_MEMORY_INIT, desc->total_size);
@@ -320,6 +347,9 @@ void *qd_alloc(qd_alloc_type_desc_t *desc, qd_alloc_pool_t 
**tpool)
             ALLOC_CACHE_ALIGNED(size, item);
             if (item == 0)
                 break;
+#ifdef QD_MEMORY_DEBUG
+            DEQ_ITEM_INIT(item);
+#endif
             if (!push_stack(&pool->free_list, item)) {
                 free(item);
                 break;
@@ -337,6 +367,12 @@ void *qd_alloc(qd_alloc_type_desc_t *desc, qd_alloc_pool_t 
**tpool)
     if (item) {
 #ifdef QD_MEMORY_DEBUG
         item->desc = desc;
+        item->backtrace_size = backtrace(item->backtrace, STACK_DEPTH);
+        gettimeofday(&item->timestamp, NULL);
+        qd_alloc_type_t *qtype = (qd_alloc_type_t*) desc->debug;
+        sys_mutex_lock(desc->lock);
+        DEQ_INSERT_TAIL(qtype->allocated, item);
+        sys_mutex_unlock(desc->lock);
         item->header = PATTERN_FRONT;
         *((uint32_t*) ((char*) &item[1] + desc->total_size))= PATTERN_BACK;
         QD_MEMORY_FILL(&item[1], QD_MEMORY_INIT, desc->total_size);
@@ -360,6 +396,10 @@ void qd_dealloc(qd_alloc_type_desc_t *desc, 
qd_alloc_pool_t **tpool, char *p)
     assert (item->header  == PATTERN_FRONT);
     assert (*((uint32_t*) (p + desc->total_size)) == PATTERN_BACK);
     assert (item->desc == desc);  // Check for double-free
+    qd_alloc_type_t *qtype = (qd_alloc_type_t*) desc->debug;
+    sys_mutex_lock(desc->lock);
+    DEQ_REMOVE(qtype->allocated, item);
+    sys_mutex_unlock(desc->lock);
     item->desc = 0;
     QD_MEMORY_FILL(p, QD_MEMORY_FREE, desc->total_size);
 #endif
@@ -501,11 +541,31 @@ void qd_alloc_finalize(void)
         // Check the stats for lost items
         //
 #if QD_MEMORY_STATS
-        if (dump_file && desc->stats->total_free_to_heap < 
desc->stats->total_alloc_from_heap)
+        if (dump_file && desc->stats->total_free_to_heap < 
desc->stats->total_alloc_from_heap) {
             fprintf(dump_file,
                     "alloc.c: Items of type '%s' remain allocated at shutdown: 
%"PRId64"\n",
                     desc->type_name,
                     desc->stats->total_alloc_from_heap - 
desc->stats->total_free_to_heap);
+#ifdef QD_MEMORY_DEBUG
+            qd_alloc_type_t *qtype = (qd_alloc_type_t*) desc->debug;
+            qd_alloc_item_t *item = DEQ_HEAD(qtype->allocated);
+            char buf[100];
+            while (item) {
+                size_t i;
+                char **strings;
+                strings = backtrace_symbols(item->backtrace, 
item->backtrace_size);
+
+                qd_log_formatted_time(&item->timestamp, buf, 100);
+                fprintf(dump_file, "Allocation time: %s\n", buf);
+
+                for (i = 0; i < item->backtrace_size; i++)
+                    fprintf(dump_file, "%s\n", strings[i]);
+                free(strings);
+                fprintf(dump_file, "\n");
+                item = DEQ_NEXT(item);
+            }
+#endif
+        }
 #endif
 
         //
diff --git a/src/log.c b/src/log.c
index 0d94006..58c0b31 100644
--- a/src/log.c
+++ b/src/log.c
@@ -33,7 +33,6 @@
 #include <stdarg.h>
 #include <stdio.h>
 #include <string.h>
-#include <time.h>
 #include <syslog.h>
 
 #define TEXT_MAX QD_LOG_TEXT_MAX
@@ -91,6 +90,17 @@ void qd_log_global_options(const char* _format, bool _utc) {
     utc = _utc;
 }
 
+
+void qd_log_formatted_time(struct timeval *time, char *buf, size_t buflen)
+{
+    time_t sec = time->tv_sec;
+    struct tm *tm_time = utc ? gmtime(&sec) : localtime(&sec);
+    char fmt[100];
+    strftime(fmt, sizeof fmt, format, tm_time);
+    snprintf(buf, buflen, fmt, time->tv_usec);
+}
+
+
 static const char* SINK_STDOUT = "stdout";
 static const char* SINK_STDERR = "stderr";
 static const char* SINK_SYSLOG = "syslog";
@@ -309,11 +319,7 @@ static void write_log(qd_log_source_t *log_source, 
qd_log_entry_t *entry)
         char buf[100];
         buf[0] = '\0';
 
-        time_t sec = entry->time.tv_sec;
-        struct tm *time = utc ? gmtime(&sec) : localtime(&sec);
-        char fmt[100];
-        strftime(fmt, sizeof fmt, format, time);
-        snprintf(buf, 100, fmt, entry->time.tv_usec);
+        qd_log_formatted_time(&entry->time, buf, 100);
 
         aprintf(&begin, end, "%s ", buf);
     }
diff --git a/src/log_private.h b/src/log_private.h
index 1f51490..a7abd22 100644
--- a/src/log_private.h
+++ b/src/log_private.h
@@ -20,10 +20,12 @@
  */
 
 #include <qpid/dispatch/log.h>
+#include <time.h>
 
 void qd_log_initialize(void);
 void qd_log_global_options(const char* format, bool utc);
 void qd_log_finalize(void);
+void qd_log_formatted_time(struct timeval *time, char *buf, size_t buflen);
 
 #define QD_LOG_TEXT_MAX 2048
 #endif


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@qpid.apache.org
For additional commands, e-mail: commits-h...@qpid.apache.org

Reply via email to