Fix the attempted allocation size in OOM error messages

[TimWolla]

The sizes reported in the error messages previously didn't match the sizes that were actually checked against the memory limit. This can result in confusing error reports, because the reported size often tends to be much smaller than the actual chunk allocation size used in accounting.

Consider the following example script:

<?php
$foo = [];
while (true) {
	var_dump(memory_get_usage());
	$foo[] = new stdClass();
}

Executing the script as

sapi/cli/php -dmemory_limit=5145728 oom.php

results in:

int(3833360)
int(3833440)
int(3833520)

Fatal error: Allowed memory size of 5145728 bytes exhausted at
php-src/Zend/zend_objects_API.c:136 (tried to allocate 524320 bytes) in
php-src/oom.php on line 5

With each iteration the actual memory usage grows by 80 bytes. The error message reports roughly 512 KiB of additional usage, possibly for an array resizing, but even for those additional 512 KiB the last observed memory usage does not exceed the memory limit of 5145728 Bytes.

This is because actually a chunk of 2 MiB is going to be allocated and that is what is checked. The following output was created with this patch applied:

int(3833360)
int(3833440)
int(3833520)

Fatal error: Allowed memory size of 5145728 bytes exhausted at
php-src/Zend/zend_objects_API.c:136 (tried to allocate 2097152 bytes)
in php-src/oom.php on line 5

With the fixed output the attempted allocation clearly exceeds the memory limit.

In a further change the error message could possibly be adjusted to also report the current memory usage instead of just the limit + the attempted allocation.

[bwoebi]

This may be confusing like "I'm just doing a small allocation on this line, where does a 2 MB allocation come from?!".

If you want to be actually more clear, both numbers would need to be in the error message.

[TimWolla]

This may be confusing like "I'm just doing a small allocation on this line, where does a 2 MB allocation come from?!".

It already is confusing, because it showed 512 KiB of additional memory (when in reality it's 2 MiB) in the message even when only 80 extra bytes per iteration are required. I believe it's less confusing to show the 2 MiB there.

If you want to be actually more clear, both numbers would need to be in the error message.

I'd also be fine with that. As the commit message says at the end, the current allocation watermark should also be shown. How about something along these lines:

Allowed memory size of 5145728 bytes exhausted by 784944 bytes. Allocated 3833520 bytes and need to allocate 2097152 bytes to satisfy a request for 524320 bytes.

It mentions:

• The memory limit.
• How much additional limit would be required.
• How much memory is in use.
• The size of the actual allocation.
• The size of the request that caused the request.

This should probably be all information that is relevant to diagnose the issue.

For realloc possibly:

Allowed memory size of 5145728 bytes exhausted by 784944 bytes. Allocated 3833520 bytes and need to allocate 2097152 bytes to satisfy a reallocation from 1234 to 5678 bytes.

[TimWolla]

@bwoebi Do you happen to know if it's correct that these two numbers already differ depending on ZEND_DEBUG (i.e. size vs ZEND_MM_PAGE_SIZE * pages_count)?

[dstogov]

I don't think this makes sense. "Tried to allocate %zu bytes" just won't give any info except of constant chunk size.

Script requests "size" bytes, MM doesn't find free pages and needs a new chunk.

[iluuu1994]

It might be better to extend the message with "(allocating in 2MB chunks)". But maybe it's better drop the "tried to allocate n bytes" altogether, as it is non-obvious what the engine even allocates memory for, except for specific cases like loading files into memory. In pretty much every case, a good stack trace would be more helpful than the byte size.

[TimWolla]

But maybe it's better drop the "tried to allocate n bytes" altogether

I have found the amount to be useful in the past. Or rather I have found it useful to either see a "small number" or "huge number" there, because it can be an indicator of a possible cause.

In pretty much every case, a good stack trace would be more helpful than the byte size.

Agreed. Especially it would be helpful to be able to gracefully handle an exceeded memory limit to cleanly wind down processing. I've tested around with that in TimWolla@45846cc, that's how I found out about the confusing error messages resulting in this PR.

[arnaud-lb]

In pretty much every case, a good stack trace would be more helpful than the byte size.

Agreed. Especially it would be helpful to be able to gracefully handle an exceeded memory limit to cleanly wind down processing. I've tested around with that in TimWolla@45846cc, that's how I found out about the confusing error messages resulting in this PR.

This would be very useful indeed. @TimWolla did you consider printing a stack trace when a fatal error is thrown? This would handle the case of a single allocation exceeding the soft and hard limit at the same time, and all fatal errors would benefit from this.

[TimWolla]

did you consider printing a stack trace when a fatal error is thrown?

No. One thing is that I don't want to dive into the engine more than necessary [1], another thing is that I expect the hard memory limit being exceeded to be a rare thing once the soft limit is there. For other types of Fatal Error (e.g. uncaught exception or max execution time), the stack trace IMO is not all that useful.

[1] And even the soft memory limit thing is deeper than I'm comfortable with 😄

[TimWolla]

How about something along these lines:

As multiple persons said that the change to the actual size would also be misleading, I went ahead and made the change to include all relevant numbers within the error message.

What do you think? You can see it in action in the failing tests that expect the previous phrasing.

The updated implementation of zend_mm_safe_error() is not exactly pretty. There currently is no variant zend_error_noreturn that takes va_list. It worked as a PoC, though.