Press "Enter" to skip to content

PHP Memory Management — Analyzing a Low-Probability Core

A colleague forwarded me the bt info of a low-probability Core that had occurred a few times over a long period in one of our company's product lines, asking me to help analyze the cause.
The bt stack is as follows (path info replaced with *):

#0  0x00000000004a75e5 in _zend_mm_alloc_int (heap=0xd61260, size=79)
at /*/php-5.2.6/Zend/zend_alloc.c:1879
#1  0x000000000048d3cd in vspprintf (pbuf=0x7fbffe9cd8, max_len=1024, format=Variable "format" is not available.
)
    at /*/php-5.2.6/main/spprintf.c:224
#2  0x0000000000489747 in php_error_cb (type=1, error_filename=0x2a9a787ee8 "/*/application/helpers/util.php",
    error_lineno=1149, format=Variable "format" is not available.
) at /*/php-5.2.6/main/main.c:799
#3  0x000000000061db35 in soap_error_handler (error_num=1,
    error_filename=0x2a9a787ee8 "/*/application/helpers/util.php", error_lineno=1149,
    format=0x7b9cb8 "Maximum execution time of %d second%s exceeded", args=0x7fbffea3b0)
    at /*/php-5.2.6/ext/soap/soap.c:2178
#4  0x00000000004c2576 in zend_error (type=1, format=0x7b9cb8 "Maximum execution time of %d second%s exceeded")
    at /*/php-5.2.6/Zend/zend.c:976
#5  <signal handler called>
#6  0x00000000004a720f in _zend_mm_free_int (heap=0xd61260, p=Variable "p" is not available.
) at /*/php-5.2.6/Zend/zend_alloc.c:844
...and so on, omitted

Looking at this call stack, you'll notice #5 signal handler called. But didn't I remember that during zend_mm_free_int, interruptions were blocked? How did it still get diverted into the signal-handling process? It later turned out that when I looked before I didn't dig deeper — in zend_mm_free_int:

HANDLE_BLOCK_INTERRUPTIONS();
....
HANDLE_UNBLOCK_INTERRUPTIONS();

at present, this is just a decoration (before php-5.2.17).
OK, setting that aside, how exactly was this core produced?
First, let me introduce the core structure of PHP memory management, zend_mm_heap, as shown below:

Zend MM heap

For free_buckets, it stores pointers to all small memory blocks, with a corresponding free_bitmap indicating which indices in free_buckets are available (have real memory).
Then, in the function call of zend_mm_free_int, when reclaiming memory, if it finds that adjacent memory is free, it will merge them. The specific logic:

    HANDLE_BLOCK_INTERRUPTIONS();
    heap->size -= size;
    next_block = ZEND_MM_BLOCK_AT(mm_block, size);
    if (ZEND_MM_IS_FREE_BLOCK(next_block)) {
        zend_mm_remove_from_free_list(heap, (zend_mm_free_block *) next_block);
        size += ZEND_MM_FREE_BLOCK_SIZE(next_block);
    }
    //and so on, omitted

And in the call to zend_mm_remove_from_free_list, the originally adjacent memory is removed from free_buckets:

//abridged
    prev->next_free_block = next;
    next->prev_free_block = prev;
        if (EXPECTED(ZEND_MM_SMALL_SIZE(ZEND_MM_FREE_BLOCK_SIZE(mm_block)))) {
            if (EXPECTED(prev == next)) {
                size_t index = ZEND_MM_BUCKET_INDEX(ZEND_MM_FREE_BLOCK_SIZE(mm_block));
                if (EXPECTED(heap->free_buckets[index*2] == heap->free_buckets[index*2+1])) {
//note this line
heap->free_bitmap &= ~(ZEND_MM_LONG_CONST(1) << index);
                }
            }
        } else if (UNEXPECTED(mm_block->parent != NULL)) {
            goto subst_block;
        }
//abridged

As shown in the code above, after removing this block from free_buckets, if this block is the only block in its corresponding index, then the availability indicator in free_bitmap is turned off..
The problem is right here
When the code was executing this line, the business-logic timeout signal was triggered, so this line of code was not executed; it diverted into the signal-handling flow.

#4  0x00000000004c2576 in zend_error (type=1, format=0x7b9cb8 "Maximum execution time of %d second%s exceeded")
    at /*/php-5.2.6/Zend/zend.c:976
#5  <signal handler called>
#6  0x00000000004a720f in _zend_mm_free_int (heap=0xd61260, p=Variable "p" is not available.
) at /*/php-5.2.6/Zend/zend_alloc.c:844

And in the error-handling logic, memory is again allocated for the error message, and it just happened to find the memory indicated by this incorrect free_bitmap:

#0  0x00000000004a75e5 in _zend_mm_alloc_int (heap=0xd61260, size=79)
at /*/php-5.2.6/Zend/zend_alloc.c:1879
#1  0x000000000048d3cd in vspprintf (pbuf=0x7fbffe9cd8, max_len=1024, format=Variable "format" is not available.
)

At this point, the pointer at the corresponding index in free_buckets is an unusable pointer (pointing to itself).
This leads to a segfault-exit in the logic of alloc_init:

# define ZEND_MM_CHECK_BLOCK_LINKAGE(block) \
    if (UNEXPECTED((block)->info._size != ZEND_MM_BLOCK_AT(block, ZEND_MM_FREE_BLOCK_SIZE(block))->info._prev) || \
        UNEXPECTED(!UNEXPECTED(ZEND_MM_IS_FIRST_BLOCK(block)) && \
        UNEXPECTED(ZEND_MM_PREV_BLOCK(block)->info._size != (block)->info._prev))) { \
        zend_mm_panic("zend_mm_heap corrupted"); \
    }

The cause has been found. So how to avoid or handle this problem?
Actually, when the core occurred, the business logic had already timed out and errored. And this core is a product of some characteristics of PHP itself; it can't quite be called a PHP bug (at least it has a signal-blocking operation that looks like it does something). You can only say it's a low-probability event...

Be First to Comment

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.