Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Robert Haas]

On Tue, Sep 20, 2016 at 9:25 PM, Michael Paquier
 wrote:
> On Wed, Sep 21, 2016 at 12:32 AM, Robert Haas  wrote:
>> For what it's worth, I think it's fine.  Good error messages are a useful 
>> thing.
>>
>> More generally, I think the whole patch looks good and should be committed.
>
> Hm. I'd think that it is still more portable to just issue a WARNING
> message in palloc_extended() when MCXT_ALLOC_NO_OOM then. Other code
> paths could benefit from that as well, and the patch proposed does
> nothing for the other places calling it. I am fine to write a patch
> for this purpose if you agree on that.

No, I strongly disagree with that.  I think when you pass
MCXT_ALLOC_NO_OOM, you're saying that you are prepared to deal with a
NULL return value.  It becomes your job to decide whether to emit any
log message and which one to emit.  If palloc_extended() insists on
emitting a warning regardless, the caller can't now emit a more
specific message without creating redundant log chatter.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Michael Paquier]

On Wed, Sep 21, 2016 at 10:25 AM, Michael Paquier
 wrote:
> On Wed, Sep 21, 2016 at 12:32 AM, Robert Haas  wrote:
>> For what it's worth, I think it's fine.  Good error messages are a useful 
>> thing.
>>
>> More generally, I think the whole patch looks good and should be committed.
>
> Hm. I'd think that it is still more portable to just issue a WARNING
> message in palloc_extended() when MCXT_ALLOC_NO_OOM then. Other code
> paths could benefit from that as well, and the patch proposed does
> nothing for the other places calling it. I am fine to write a patch
> for this purpose if you agree on that.

Or in short the attached. All the other callers of palloc_extended
benefit from that.
-- 
Michael
diff --git a/src/backend/utils/mmgr/mcxt.c b/src/backend/utils/mmgr/mcxt.c
index 5cf388f..52b9c1b 100644
--- a/src/backend/utils/mmgr/mcxt.c
+++ b/src/backend/utils/mmgr/mcxt.c
@@ -973,6 +973,10 @@ palloc_extended(Size size, int flags)
 errmsg("out of memory"),
 errdetail("Failed on request of size 
%zu.", size)));
}
+   ereport(WARNING,
+   (errcode(ERRCODE_OUT_OF_MEMORY),
+errmsg("out of memory"),
+errdetail("Failed on request of size %zu.", 
size)));
return NULL;
}
 
diff --git a/src/common/fe_memutils.c b/src/common/fe_memutils.c
index 58c5c4c..0d44ef6 100644
--- a/src/common/fe_memutils.c
+++ b/src/common/fe_memutils.c
@@ -30,9 +30,9 @@ pg_malloc_internal(size_t size, int flags)
tmp = malloc(size);
if (tmp == NULL)
{
+   fprintf(stderr, _("could not allocate %zu bytes of memory\n"), 
size);
if ((flags & MCXT_ALLOC_NO_OOM) == 0)
{
-   fprintf(stderr, _("out of memory\n"));
exit(EXIT_FAILURE);
}
return NULL;

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Michael Paquier]

On Wed, Sep 21, 2016 at 12:32 AM, Robert Haas  wrote:
> For what it's worth, I think it's fine.  Good error messages are a useful 
> thing.
>
> More generally, I think the whole patch looks good and should be committed.

Hm. I'd think that it is still more portable to just issue a WARNING
message in palloc_extended() when MCXT_ALLOC_NO_OOM then. Other code
paths could benefit from that as well, and the patch proposed does
nothing for the other places calling it. I am fine to write a patch
for this purpose if you agree on that.
-- 
Michael


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Robert Haas]

On Mon, Jul 11, 2016 at 12:04 AM, Michael Paquier
 wrote:
> On Sat, Jul 9, 2016 at 2:58 AM, Shoaib Lari  wrote:
>> Besides making the error message more informative, we had to modify
>> allocate_recordbuf() to return the actual number of bytes that were being
>> allocated.
>
> -   report_invalid_record(state, "record length %u at %X/%X too long",
> - total_len,
> - (uint32) (RecPtr >> 32), (uint32) RecPtr);
> +   report_invalid_record(state,
> + "cannot allocate %u bytes for record
> length %u at %X/%X",
> + newSizeOut, total_len, (uint32) (RecPtr >> 32),
> + (uint32) RecPtr);
>
> It does not look like a good idea to me to complicate the interface of
> allocate_recordbuf just to make more verbose one error message, ...

For what it's worth, I think it's fine.  Good error messages are a useful thing.

More generally, I think the whole patch looks good and should be committed.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Shoaib Lari]

Thank you for the feedback.

We had encountered this error message when allocating a record buf of 344
bytes.  The message "record length 344 at %X/%X too long" along with the
comment /* We treat this as a "bogus data" condition */  masked the OOM
condition, implying an error in log record size calculation logic.

The actual allocation that failed was for 5 * Max(BLCKSZ, XLOG_BLCKSZ), a
much larger allocation.

Shoaib


On Sun, Jul 10, 2016 at 10:58 PM, Craig Ringer 
wrote:

>
>
> On 11 July 2016 at 12:04, Michael Paquier 
> wrote:
>
>> On Sat, Jul 9, 2016 at 2:58 AM, Shoaib Lari  wrote:
>> > Besides making the error message more informative, we had to modify
>> > allocate_recordbuf() to return the actual number of bytes that were
>> being
>> > allocated.
>>
>> -   report_invalid_record(state, "record length %u at %X/%X too long",
>> - total_len,
>> - (uint32) (RecPtr >> 32), (uint32) RecPtr);
>> +   report_invalid_record(state,
>> + "cannot allocate %u bytes for record
>> length %u at %X/%X",
>> + newSizeOut, total_len, (uint32) (RecPtr >>
>> 32),
>> + (uint32) RecPtr);
>>
>> It does not look like a good idea to me to complicate the interface of
>> allocate_recordbuf just to make more verbose one error message,
>> meaning that it basically a complain related to the fact that
>> palloc_extended(MCXT_ALLOC_NO_OOM) does not mention to the user the
>> size that it has tried to allocate before returning NULL. Do you have
>> a use case that would prove to be useful if this extra piece of
>> information is provided? Because it seems to me that we don't really
>> care if we know how much memory it has failed to allocate, we only
>> want to know that it *has* failed and take actions only based on that.
>>
>
> I actually find details of how much memory we tried to allocate to be
> really useful in other places that do emit it. Sometimes it's been an
> important clue when trying to figure out what's going on on a remote system
> with no or limited access. Even if it just tells me "we were probably
> incrementally allocating lots of small values since this failure is small"
> vs "this allocation is huge, look for something unusually large" or "this
> allocation is impossibly huge / some suspicious value look for memory
> corruption".
>
> I tend to agree with your suggestion about a better approach but do think
> emitting details on allocation failures is useful. At least when people
> turn VM overcommit off ...
>
> --
>  Craig Ringer   http://www.2ndQuadrant.com/
>  PostgreSQL Development, 24x7 Support, Training & Services
>

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Craig Ringer]

On 11 July 2016 at 12:04, Michael Paquier  wrote:

> On Sat, Jul 9, 2016 at 2:58 AM, Shoaib Lari  wrote:
> > Besides making the error message more informative, we had to modify
> > allocate_recordbuf() to return the actual number of bytes that were being
> > allocated.
>
> -   report_invalid_record(state, "record length %u at %X/%X too long",
> - total_len,
> - (uint32) (RecPtr >> 32), (uint32) RecPtr);
> +   report_invalid_record(state,
> + "cannot allocate %u bytes for record
> length %u at %X/%X",
> + newSizeOut, total_len, (uint32) (RecPtr >>
> 32),
> + (uint32) RecPtr);
>
> It does not look like a good idea to me to complicate the interface of
> allocate_recordbuf just to make more verbose one error message,
> meaning that it basically a complain related to the fact that
> palloc_extended(MCXT_ALLOC_NO_OOM) does not mention to the user the
> size that it has tried to allocate before returning NULL. Do you have
> a use case that would prove to be useful if this extra piece of
> information is provided? Because it seems to me that we don't really
> care if we know how much memory it has failed to allocate, we only
> want to know that it *has* failed and take actions only based on that.
>

I actually find details of how much memory we tried to allocate to be
really useful in other places that do emit it. Sometimes it's been an
important clue when trying to figure out what's going on on a remote system
with no or limited access. Even if it just tells me "we were probably
incrementally allocating lots of small values since this failure is small"
vs "this allocation is huge, look for something unusually large" or "this
allocation is impossibly huge / some suspicious value look for memory
corruption".

I tend to agree with your suggestion about a better approach but do think
emitting details on allocation failures is useful. At least when people
turn VM overcommit off ...

-- 
 Craig Ringer   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

Re: [HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Michael Paquier]

On Sat, Jul 9, 2016 at 2:58 AM, Shoaib Lari  wrote:
> Besides making the error message more informative, we had to modify
> allocate_recordbuf() to return the actual number of bytes that were being
> allocated.

-   report_invalid_record(state, "record length %u at %X/%X too long",
- total_len,
- (uint32) (RecPtr >> 32), (uint32) RecPtr);
+   report_invalid_record(state,
+ "cannot allocate %u bytes for record
length %u at %X/%X",
+ newSizeOut, total_len, (uint32) (RecPtr >> 32),
+ (uint32) RecPtr);

It does not look like a good idea to me to complicate the interface of
allocate_recordbuf just to make more verbose one error message,
meaning that it basically a complain related to the fact that
palloc_extended(MCXT_ALLOC_NO_OOM) does not mention to the user the
size that it has tried to allocate before returning NULL. Do you have
a use case that would prove to be useful if this extra piece of
information is provided? Because it seems to me that we don't really
care if we know how much memory it has failed to allocate, we only
want to know that it *has* failed and take actions only based on that.

And even if we make this thing more verbose, a better approach would
be surely to generate a WARNING message for backends in mcxt.c and
have something printed to stderr for frontends in fe_memutils.c
without calling exit().
-- 
Michael


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

[HACKERS] Fix Error Message for allocate_recordbuf() Failure

[Shoaib Lari]

Hello,

Attached is a patch for xlogreader.c for a more informative error message
for allocate_recordbuf() failure.

The patch details are:


   - Project name.: None



   - Uniquely identifiable file name, so we can tell difference between
   your v1 and v24.:  src/backend/access/transam/xlogreader.c



   - What the patch does in a short paragraph.:

The patch enhances the error message when memory cannot be allocated to
extend the readRecordBuf.  The previous error message was implying an
invalid (too long) record length and also did not specify how much memory
we were trying to allocate when the memory allocation failure happened.

We have observed failed allocations in production systems where the
reclength was only 344 bytes, but the extended allocation of 5 *
Max(BLKSIZE, XLOG_BLCKSZ) failed due to out of memory.



   - Whether the patch is for discussion or for application (see WIP notes
   below): for application.



   - Which branch the patch is against (ordinarily this will be *master*).
   For more on branches in PostgreSQL, see Using Back Branches
   .:
master



   - Whether it compiles and tests successfully, so we know nothing obvious
   is broken.:  Yes.  We ran make check and all 166 tests passed.



   - Whether it contains any platform-specific items and if so, has it been
   tested on other platforms.:  Nothing platform specific.



   - Confirm that the patch includes regression tests
    to check
   the new feature actually works as described.:  None.



   - Include documentation on how to use the new feature, including
   examples. See the documentation documentation
    for more
   information.:  None needed.



   - Describe the effect your patch has on performance, if any.:  None.



   - Try to include a few lines about why you chose to do things particular
   ways, rather than let your reviewer guess what was happening. This can be
   done as code comments, but it might also be an additional reviewers' guide,
   or additions to a README file in one of the code directories.:

Besides making the error message more informative, we had to modify
allocate_recordbuf() to return the actual number of bytes that were being
allocated.



   - If your patch addresses a Todo
 item,
   please give the name of the Todo item in your email. This is so that the
   reviewers will know that the item needs to be marked as done if your patch
   is applied.:  None.



Thank you.

Shoaib Lari


fix_error_message_for_allocate_recordbuf_failure.patch
Description: Binary data

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers