DEBUG: pools: print the contents surrounding the expected tag location
authorWilly Tarreau <w@1wt.eu>
Tue, 12 Sep 2023 15:30:54 +0000 (17:30 +0200)
committerWilly Tarreau <w@1wt.eu>
Tue, 12 Sep 2023 16:14:05 +0000 (18:14 +0200)
When no tag matches a known pool, we can inspect around to help figure
what could have possibly overwritten memory. The contents are printed
one machine word per line in hex, then using printable characters, and
when they can be resolved to a pointer, either the pool's pointer name
or a resolvable symbol with offset. The goal here is to help recognize
what is easily identifiable in memory.

For example applying the following patch to stream_free():

  - pool_free(pool_head_stream, s);
  + pool_free(pool_head_stream, (void*)s+1);

Causes the following dump to be emitted:

  FATAL: pool inconsistency detected in thread 1: tag mismatch on free().
    caller: 0x59e968 (stream_free+0x6d8/0xa0a)
    item: 0x13df5c1
    pool: 0x12782c0 ('stream', size 888, real 904, users 1)
  Tag does not match (0x4f00000000012782). Tag does not match any other pool.
  Contents around address 0x13df5c1+888=0x13df939:
         0x13df918 [00 00 00 00 00 00 00 00] [........]
         0x13df920 [00 00 00 00 00 00 00 00] [........]
         0x13df928 [00 00 00 00 00 00 00 00] [........]
         0x13df930 [00 00 00 00 00 00 00 00] [........]
         0x13df938 [c0 82 27 01 00 00 00 00] [..'.....] [pool:stream]
         0x13df940 [4f c0 59 00 00 00 00 00] [O.Y.....] [stream_new+0x4f/0xbec]
         0x13df948 [49 46 49 43 41 54 45 2d] [IFICATE-]
         0x13df950 [81 02 00 00 00 00 00 00] [........]
         0x13df958 [df 13 00 00 00 00 00 00] [........]
  Other possible callers:
  (...)

We notice that the tag references pool_head_stream with the allocation
point in stream_new. Another benefit is that a caller may be figured
from the tag even if the "caller" feature is not enabled, because upon
a free() we always put the caller's location into the tag. This should
be sufficient to debug most cases that normally require gdb.

src/pool.c

index 37c8485..b711263 100644 (file)
@@ -989,8 +989,53 @@ void pool_inspect_item(const char *msg, struct pool_head *pool, const void *item
                                }
                        }
 
-                       if (!the_pool)
-                               chunk_appendf(&trash, "Tag does not match any other pool.\n");
+                       if (!the_pool) {
+                               const char *start, *end, *p;
+
+                               pool_mark = (const void **)(((char *)item) + pool->size);
+                               chunk_appendf(&trash,
+                                             "Tag does not match any other pool.\n"
+                                             "Contents around address %p+%lu=%p:\n",
+                                             item, (ulong)((const void*)pool_mark - (const void*)item),
+                                             pool_mark);
+
+                               /* dump in word-sized blocks */
+                               start = (const void *)(((uintptr_t)pool_mark - 32) & -sizeof(void*));
+                               end   = (const void *)(((uintptr_t)pool_mark + 32 + sizeof(void*) - 1) & -sizeof(void*));
+
+                               while (start < end) {
+                                       dump_addr_and_bytes(&trash, "  ", start, sizeof(void*));
+                                       chunk_strcat(&trash, " [");
+                                       for (p = start; p < start + sizeof(void*); p++) {
+                                               if (!may_access(p))
+                                                       chunk_strcat(&trash, "*");
+                                               else if (isprint((unsigned char)*p))
+                                                       chunk_appendf(&trash, "%c", *p);
+                                               else
+                                                       chunk_strcat(&trash, ".");
+                                       }
+
+                                       if (may_access(start))
+                                               tag = *(const void **)start;
+                                       else
+                                               tag = NULL;
+
+                                       if (tag == pool) {
+                                               /* the pool can often be there so let's detect it */
+                                               chunk_appendf(&trash, "] [pool:%s", pool->name);
+                                       }
+                                       else if (tag) {
+                                               /* print pointers that resolve to a symbol */
+                                               size_t back_data = trash.data;
+                                               chunk_strcat(&trash, "] [");
+                                               if (!resolve_sym_name(&trash, NULL, tag))
+                                                       trash.data = back_data;
+                                       }
+
+                                       chunk_strcat(&trash, "]\n");
+                                       start = p;
+                               }
+                       }
                }
        }