DEBUG: pools: inspect pools on fatal error and dump information found

It's a bit frustrating sometimes to see pool checks catch a bug but not
provide exploitable information without a core.

Here we're adding a function "pool_inspect_item()" which is called just
before aborting in pool_check_pattern() and POOL_DEBUG_CHECK_MARK() and
which will display the error type, the pool's pointer and name, and will
try to check if the item's tag matches the pool, and if not, will iterate
over all pools to see if one would be a better candidate, then will try
to figure the last known caller and possibly other likely candidates if
the pool's tag is not sufficiently trusted. This typically helps better
diagnose corruption in use-after-free scenarios, or freeing to a pool
that differs from the one the object was allocated from, and will also
indicate calling points that may help figure where an object was last
released or allocated. The info is printed on stderr just before the
backtrace.

For example, the recent off-by-one test in the PPv2 changes would have
produced the following output in vtest logs:

  ***  h1    debug|FATAL: pool inconsistency detected in thread 1: tag mismatch on free().
  ***  h1    debug|  caller: 0x62bb87 (conn_free+0x147/0x3c5)
  ***  h1    debug|  pool: 0x2211ec0 ('pp_tlv_256', size 304, real 320, users 1)
  ***  h1    debug|Tag does not match. Possible origin pool(s):
  ***  h1    debug|  tag: @0x2565530 = 0x2216740 (pp_tlv_128, size 176, real 192, users 1)
  ***  h1    debug|Recorded caller if pool 'pp_tlv_128':
  ***  h1    debug|  @0x2565538 (+0184) = 0x62c76d (conn_recv_proxy+0x4cd/0xa24)

A mismatch in the allocated/released pool is already visible, and the
callers confirm it once resolved, where the allocator indeed allocates
from pp_tlv_128 and conn_free() releases to pp_tlv_256:

  $ addr2line -spafe ./haproxy <<< $'0x62bb87\n0x62c76d'
  0x000000000062bb87: conn_free at connection.c:568
  0x000000000062c76d: conn_recv_proxy at connection.c:1177

diff --git a/include/haproxy/pool.h b/include/haproxy/pool.h
index 506e436265386e5b406efafd23fd11b6f920de4c..133e954fc92e81fcdaa97dfbd6654367938d369d 100644 (file)
--- a/include/haproxy/pool.h
+++ b/include/haproxy/pool.h
@@ -76,8 +76,10 @@
                typeof(item) __i = (item);                              \
                if (likely(!(pool_debugging & POOL_DBG_TAG)))           \
                        break;                                          \
-               if (*(typeof(pool)*)(((char *)__i) + __p->size) != __p) \
+               if (*(typeof(pool)*)(((char *)__i) + __p->size) != __p) { \
+                       pool_inspect_item("tag mismatch on free()", pool, item, caller); \
                        ABORT_NOW();                                    \
+               }                                                       \
        } while (0)
 
 /* It's possible to trace callers of pool_free() by placing their pointer
@@ -121,6 +123,7 @@ void *pool_destroy(struct pool_head *pool);
 void pool_destroy_all(void);
 void *__pool_alloc(struct pool_head *pool, unsigned int flags);
 void __pool_free(struct pool_head *pool, void *ptr);
+void pool_inspect_item(const char *msg, struct pool_head *pool, const void *item, const void *caller);
 
 
 /****************** Thread-local cache management ******************/

diff --git a/src/pool.c b/src/pool.c
index 13af300082f692149c13e887ccdae04783119c5c..6c49178b44d0aaeb56b686348d964acb924e7cb3 100644 (file)
--- a/src/pool.c
+++ b/src/pool.c
@@ -495,8 +495,10 @@ void pool_check_pattern(struct pool_cache_head *pch, struct pool_head *pool, str
        ofs = sizeof(*item) / sizeof(*ptr);
        u = ptr[ofs++];
        while (ofs < size / sizeof(*ptr)) {
-               if (unlikely(ptr[ofs] != u))
+               if (unlikely(ptr[ofs] != u)) {
+                       pool_inspect_item("cache corruption detected", pool, item, caller);
                        ABORT_NOW();
+               }
                ofs++;
        }
 }
@@ -935,6 +937,101 @@ void pool_destroy_all()
        }
 }
 
+/* carefully inspects an item upon fatal error and emit diagnostics */
+void pool_inspect_item(const char *msg, struct pool_head *pool, const void *item, const void *caller)
+{
+       const struct pool_head *the_pool = NULL;
+
+       chunk_printf(&trash,
+                    "FATAL: pool inconsistency detected in thread %d: %s.\n"
+                    "  caller: %p (",
+                    tid + 1, msg, caller);
+
+       resolve_sym_name(&trash, NULL, caller);
+
+       chunk_appendf(&trash,
+                     ")\n"
+                     "  pool: %p ('%s', size %u, real %u, users %u)\n",
+                     pool, pool->name, pool->size, pool->alloc_sz, pool->users);
+
+       if (pool_debugging & POOL_DBG_TAG) {
+               const void **pool_mark;
+               struct pool_head *ph;
+               const void *tag;
+
+               pool_mark = (const void **)(((char *)item) + pool->size);
+               tag =  may_access(pool_mark) ? *pool_mark : NULL;
+               if (tag == pool) {
+                       chunk_appendf(&trash, "  tag: @%p = %p (%s)\n", pool_mark, tag, pool->name);
+                       the_pool = pool;
+               }
+               else {
+                       chunk_appendf(&trash, "Tag does not match. Possible origin pool(s):\n");
+
+                       list_for_each_entry(ph, &pools, list) {
+                               pool_mark = (const void **)(((char *)item) + ph->size);
+                               if (!may_access(pool_mark))
+                                       continue;
+                               tag =  *pool_mark;
+
+                               if (tag == ph) {
+                                       chunk_appendf(&trash, "  tag: @%p = %p (%s, size %u, real %u, users %u)\n",
+                                                     pool_mark, tag, ph->name, ph->size, ph->alloc_sz, ph->users);
+                                       if (!the_pool || the_pool->size < ph->size)
+                                               the_pool = ph;
+                               }
+                       }
+
+                       if (!the_pool)
+                               chunk_appendf(&trash, "  none found.\n");
+               }
+       }
+
+       if (pool_debugging & POOL_DBG_CALLER) {
+               struct buffer *trash2 = get_trash_chunk();
+               const struct pool_head *ph;
+               const void **pool_mark;
+               const void *tag, *rec_tag;
+
+               ph = the_pool ? the_pool : pool;
+               pool_mark = (const void **)(((char *)item) + ph->alloc_sz - sizeof(void*));
+               rec_tag =  may_access(pool_mark) ? *pool_mark : NULL;
+
+               if (rec_tag && resolve_sym_name(trash2, NULL, rec_tag))
+                       chunk_appendf(&trash,
+                                     "Recorded caller if pool '%s':\n  @%p (+%04u) = %p (%s)\n",
+                                     ph->name, pool_mark, (uint)(ph->alloc_sz - sizeof(void*)),
+                                     rec_tag, trash2->area);
+
+               if (!the_pool) {
+                       /* the pool couldn't be formally verified */
+                       chunk_appendf(&trash, "Other possible callers:\n");
+                       list_for_each_entry(ph, &pools, list) {
+                               if (ph == (the_pool ? the_pool : pool))
+                                       continue;
+                               pool_mark = (const void **)(((char *)item) + ph->alloc_sz - sizeof(void*));
+                               if (!may_access(pool_mark))
+                                       continue;
+                               tag = *pool_mark;
+                               if (tag == rec_tag)
+                                       continue;
+
+                               /* see if we can resolve something */
+                               chunk_printf(trash2, "@%p (+%04u) = %p (", pool_mark, (uint)(ph->alloc_sz - sizeof(void*)), tag);
+                               if (resolve_sym_name(trash2, NULL, tag)) {
+                                       chunk_appendf(trash2, ")");
+                                       chunk_appendf(&trash,
+                                                     "  %s [as pool %s, size %u, real %u, users %u]\n",
+                                                     trash2->area, ph->name, ph->size, ph->alloc_sz, ph->users);
+                               }
+                       }
+               }
+       }
+
+       chunk_appendf(&trash, "\n");
+       DISGUISE(write(2, trash.area, trash.data));
+}
+
 /* used by qsort in "show pools" to sort by name */
 static int cmp_dump_pools_name(const void *a, const void *b)
 {