Horton

Thread

Commits

  1. Improve our support for Valgrind's leak tracking.

  2. Increment xactCompletionCount during subtransaction abort.

  3. Adjust design of per-worker parallel seqscan data struct

  4. Don't leak compiled regex(es) when an ispell cache entry is dropped.

  5. Don't leak malloc'd error string in libpqrcv_check_conninfo().

  6. Don't leak malloc'd strings when a GUC setting is rejected.

  7. Don't leak rd_statlist when a relcache entry is dropped.

  8. Don't run RelationInitTableAccessMethod in a long-lived context.

  1. Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-16T23:36:10Z

    [ starting a new thread for this ]

Andres Freund <andres@anarazel.de> writes:
> I wonder if it'd be worth starting to explicitly annotate all the places
> that do allocations and are fine with leaking them. E.g. by introducing
> malloc_permanently() or such. Right now it's hard to use valgrind et al
> to detect leaks because of all the false positives due to such "ok to
> leak" allocations.

Out of curiosity I poked at this for a little while.  It doesn't appear
to me that we leak much at all, at least not if you are willing to take
"still reachable" blocks as not-leaked.  Most of the problem is
more subtle than that.

I found just a couple of things that really seem like leaks of permanent
data structures to valgrind:

* Where ps_status.c copies the original "environ" array (on
PS_USE_CLOBBER_ARGV platforms), valgrind thinks that's all leaked,
implying that it doesn't count the "environ" global as a valid
reference to leakable data.  I was able to shut that up by also saving
the pointer into an otherwise-unused static variable.  (This is sort of
a poor man's implementation of your "malloc_permanently" idea; but I
doubt it's worth working harder, given the small number of use-cases.)

* The postmaster's sock_paths and lock_files lists appear to be leaked,
but we're doing that to ourselves by throwing away the pointers to them
without physically freeing the lists.  We can just not do that.

What I found out is that we have a lot of issues that seem to devolve
to valgrind not being sure that a block is referenced.  I identified
two main causes of that:

(1) We have a pointer, but it doesn't actually point right at the start
of the block.  A primary culprit here is lists of thingies that use the
slist and dlist infrastructure.  As an experiment, I moved the dlist_node
fields of some popular structs to the beginning, and verified that that
silences associated complaints.  I'm not sure that we want to insist on
put-the-link-first as policy (although if we did, it could provide some
notational savings perhaps).  However, unless someone knows of a way to
teach valgrind about this situation, there may be no other way to silence
those leakage complaints.  A secondary culprit is people randomly applying
CACHELINEALIGN or the like to a palloc'd address, so that the address we
have isn't pointing right at the block start.

(2) The only pointer to the start of a block is actually somewhere within
the block.  This is common in dynahash tables, where we allocate a slab
of entries in a single palloc and then thread them together.  Each entry
should have exactly one referencing pointer, but that pointer is more
likely to be elsewhere within the same palloc block than in the external
hash bucket array.  AFAICT, all cases except where the slab's first entry
is pointed to by a hash bucket pointer confuse valgrind to some extent.
I was able to hack around this by preventing dynahash from allocating
more than one hash entry per palloc, but I wonder if there's a better way.


Attached is a very crude hack, not meant for commit, that hacks things
up enough to greatly reduce the number of complaints with
"--leak-check=full".

One thing I've failed to silence so far is a bunch of entries like

==00:00:03:56.088 3467702== 1,861 bytes in 67 blocks are definitely lost in loss record 1,290 of 1,418
==00:00:03:56.088 3467702==    at 0x950650: MemoryContextAlloc (mcxt.c:827)
==00:00:03:56.088 3467702==    by 0x951710: MemoryContextStrdup (mcxt.c:1179)
==00:00:03:56.088 3467702==    by 0x91C86E: RelationInitIndexAccessInfo (relcache.c:1444)
==00:00:03:56.088 3467702==    by 0x91DA9C: RelationBuildDesc (relcache.c:1200)

which is complaining about the memory context identifiers for system
indexes' rd_indexcxt contexts.  Those are surely not being leaked in
any real sense.  I suspect that this has something to do with valgrind
not counting the context->ident fields as live pointers, but I don't
have enough valgrind-fu to fix that.

Anyway, the bottom line is that I do not think that we have all that
many uses of the pattern you postulated originally.  It's more that
we've designed some valgrind-unfriendly data structures.  We need to
improve that situation to make much progress here.

			regards, tom lane

  2. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-17T02:31:01Z

    Hi,

David, there's a question about a commit of yours below, hence adding
you.

On 2021-03-16 19:36:10 -0400, Tom Lane wrote:
> Out of curiosity I poked at this for a little while.

Cool.


> It doesn't appear to me that we leak much at all, at least not if you
> are willing to take "still reachable" blocks as not-leaked.

Well, I think for any sort of automated testing - which I think would be
useful - we'd really need *no* leaks. I know that I get a few bleats
whenever I forget to set --leak-check=no. It's also not just postgres
itself, but some of the helper tools...

And it's not just valgrind, also gcc/clang sanitizers...


> What I found out is that we have a lot of issues that seem to devolve
> to valgrind not being sure that a block is referenced.  I identified
> two main causes of that:
>
> (1) We have a pointer, but it doesn't actually point right at the start
> of the block.  A primary culprit here is lists of thingies that use the
> slist and dlist infrastructure.  As an experiment, I moved the dlist_node
> fields of some popular structs to the beginning, and verified that that
> silences associated complaints.  I'm not sure that we want to insist on
> put-the-link-first as policy (although if we did, it could provide some
> notational savings perhaps).  However, unless someone knows of a way to
> teach valgrind about this situation, there may be no other way to silence
> those leakage complaints.  A secondary culprit is people randomly applying
> CACHELINEALIGN or the like to a palloc'd address, so that the address we
> have isn't pointing right at the block start.

Hm, do you still have a backtrace / suppression for one of those? I
didn't see any in a quick (*) serial installcheck I just ran. Or I
wasn't able to pinpoint them to this issue.


I think the run might have shown a genuine leak:

==2048803== 16 bytes in 1 blocks are definitely lost in loss record 139 of 906
==2048803==    at 0x89D2EA: palloc (mcxt.c:975)
==2048803==    by 0x2392D3: heap_beginscan (heapam.c:1198)
==2048803==    by 0x264E8F: table_beginscan_strat (tableam.h:918)
==2048803==    by 0x265994: systable_beginscan (genam.c:453)
==2048803==    by 0x83C2D1: SearchCatCacheMiss (catcache.c:1359)
==2048803==    by 0x83C197: SearchCatCacheInternal (catcache.c:1299)
==2048803==    by 0x83BE9A: SearchCatCache1 (catcache.c:1167)
==2048803==    by 0x85876A: SearchSysCache1 (syscache.c:1134)
==2048803==    by 0x84CDB3: RelationInitTableAccessMethod (relcache.c:1795)
==2048803==    by 0x84F807: RelationBuildLocalRelation (relcache.c:3554)
==2048803==    by 0x303C9D: heap_create (heap.c:395)
==2048803==    by 0x305790: heap_create_with_catalog (heap.c:1291)
==2048803==    by 0x41A327: DefineRelation (tablecmds.c:885)
==2048803==    by 0x6C96B6: ProcessUtilitySlow (utility.c:1131)
==2048803==    by 0x6C948A: standard_ProcessUtility (utility.c:1034)
==2048803==    by 0x6C865F: ProcessUtility (utility.c:525)
==2048803==    by 0x6C7409: PortalRunUtility (pquery.c:1159)
==2048803==    by 0x6C7636: PortalRunMulti (pquery.c:1305)
==2048803==    by 0x6C6B11: PortalRun (pquery.c:779)
==2048803==    by 0x6C05AB: exec_simple_query (postgres.c:1173)
==2048803==
{
   <insert_a_suppression_name_here>
   Memcheck:Leak
   match-leak-kinds: definite
   fun:palloc
   fun:heap_beginscan
   fun:table_beginscan_strat
   fun:systable_beginscan
   fun:SearchCatCacheMiss
   fun:SearchCatCacheInternal
   fun:SearchCatCache1
   fun:SearchSysCache1
   fun:RelationInitTableAccessMethod
   fun:RelationBuildLocalRelation
   fun:heap_create
   fun:heap_create_with_catalog
   fun:DefineRelation
   fun:ProcessUtilitySlow
   fun:standard_ProcessUtility
   fun:ProcessUtility
   fun:PortalRunUtility
   fun:PortalRunMulti
   fun:PortalRun
   fun:exec_simple_query
}

Since 56788d2156fc heap_beginscan() allocates
	scan->rs_base.rs_private =
		palloc(sizeof(ParallelBlockTableScanWorkerData));
in heap_beginscan(). But doesn't free it in heap_endscan().

In most of the places heap scans are begun inside transient contexts,
but not always. In the above trace for example
RelationBuildLocalRelation switched to CacheMemoryContext, and nothing
switched to something else.

I'm a bit confused about the precise design of rs_private /
ParallelBlockTableScanWorkerData, specifically why it's been added to
TableScanDesc, instead of just adding it to HeapScanDesc? And why is it
allocated unconditionally, instead of just for parallel scans?


I don't think this is a false positive, even though it theoretically
could be freed by resetting CacheMemoryContext (see below)?


I saw a lot of false positives from autovacuum workers, because
AutovacMemCxt is never deleted, and because table_toast_map is created
in TopMemoryContext.  Adding an explicit
MemoryContextDelete(AutovacMemCxt) and parenting table_toast_map in that
shut that up.


Which brings me to the question why allocations in CacheMemoryContext,
AutovacMemCxt are considered to be "lost", even though they're still
"reachable" via a context reset.  I think valgrind ends up treating
memory allocated via memory contexts that still exist at process end as
lost, regardless of being reachable via the the memory pool (from
valgrinds view). Which I guess actually makes sense, for things like
TopMemoryContext and CacheContext - anything not reachable by means
other than a context reset is effectively lost for those.

For autovac launcher / worker it seems like a sensible thing to just
delete AutovacMemCxt.



> (2) The only pointer to the start of a block is actually somewhere within
> the block.  This is common in dynahash tables, where we allocate a slab
> of entries in a single palloc and then thread them together.  Each entry
> should have exactly one referencing pointer, but that pointer is more
> likely to be elsewhere within the same palloc block than in the external
> hash bucket array.  AFAICT, all cases except where the slab's first entry
> is pointed to by a hash bucket pointer confuse valgrind to some extent.
> I was able to hack around this by preventing dynahash from allocating
> more than one hash entry per palloc, but I wonder if there's a better way.

Hm. For me the number of leaks seem to stay the same with or without
your changes related to this. Is this a USE_VALGRIND build?

I'm using valgrind-3.16.1


> Attached is a very crude hack, not meant for commit, that hacks things
> up enough to greatly reduce the number of complaints with
> "--leak-check=full".
>
> One thing I've failed to silence so far is a bunch of entries like
>
> ==00:00:03:56.088 3467702== 1,861 bytes in 67 blocks are definitely lost in loss record 1,290 of 1,418
> ==00:00:03:56.088 3467702==    at 0x950650: MemoryContextAlloc (mcxt.c:827)
> ==00:00:03:56.088 3467702==    by 0x951710: MemoryContextStrdup (mcxt.c:1179)
> ==00:00:03:56.088 3467702==    by 0x91C86E: RelationInitIndexAccessInfo (relcache.c:1444)
> ==00:00:03:56.088 3467702==    by 0x91DA9C: RelationBuildDesc (relcache.c:1200)
>
> which is complaining about the memory context identifiers for system
> indexes' rd_indexcxt contexts.  Those are surely not being leaked in
> any real sense.  I suspect that this has something to do with valgrind
> not counting the context->ident fields as live pointers, but I don't
> have enough valgrind-fu to fix that.

Yea. I suspect it's related to the fact that we mark the memory as a
valgrind mempool, I'll try to investigate.


I do see a bunch of leaks bleats below fun:plpgsql_compile that I don't
yet understand. E.g.

==2054558== 32 bytes in 1 blocks are definitely lost in loss record 284 of 913
==2054558==    at 0x89D389: palloc (mcxt.c:975)
==2054558==    by 0x518732: new_list (list.c:134)
==2054558==    by 0x518C0C: lappend (list.c:341)
==2054558==    by 0x83CAE7: SearchCatCacheList (catcache.c:1691)
==2054558==    by 0x859A9C: SearchSysCacheList (syscache.c:1447)
==2054558==    by 0x313192: FuncnameGetCandidates (namespace.c:975)
==2054558==    by 0x313D91: FunctionIsVisible (namespace.c:1450)
==2054558==    by 0x7C2891: format_procedure_extended (regproc.c:375)
==2054558==    by 0x7C27C3: format_procedure (regproc.c:324)
==2054558==    by 0xA7693E1: do_compile (pl_comp.c:348)
==2054558==    by 0xA769130: plpgsql_compile (pl_comp.c:224)

and

==2054558== 30 bytes in 4 blocks are definitely lost in loss record 225 of 913
==2054558==    at 0x89D389: palloc (mcxt.c:975)
==2054558==    by 0x3ADDAE: downcase_identifier (scansup.c:52)
==2054558==    by 0x3ADD85: downcase_truncate_identifier (scansup.c:39)
==2054558==    by 0x3AB5E4: core_yylex (scan.l:1032)
==2054558==    by 0xA789B2D: internal_yylex (pl_scanner.c:321)
==2054558==    by 0xA7896E3: plpgsql_yylex (pl_scanner.c:152)
==2054558==    by 0xA780015: plpgsql_yyparse (pl_gram.c:1945)
==2054558==    by 0xA76A652: do_compile (pl_comp.c:788)
==2054558==    by 0xA769130: plpgsql_compile (pl_comp.c:224)
==2054558==    by 0xA78948F: plpgsql_validator (pl_handler.c:539)

Based on the quick look I had (dinner is calling) I didn't yet
understand how plpgsql_compile_tmp_cxt error handling works.

Greetings,

Andres Freund


(*) or not so quick, I had to figure out why valgrind was so slow. It
turned out that I had typed shared_buffers=32MB into
shared_buffers=32GB...

  3. Re: Getting better results from valgrind leak tracking

    Zhihong Yu <zyu@yugabyte.com> — 2021-03-17T03:00:36Z

    Hi,
For the second last trace involving SearchCatCacheList (catcache.c:1691),
the ctlist's members are stored in cl->members array where cl is returned
at the end of SearchCatCacheList.

Maybe this was not accounted for by valgrind ?

Cheers

On Tue, Mar 16, 2021 at 7:31 PM Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> David, there's a question about a commit of yours below, hence adding
> you.
>
> On 2021-03-16 19:36:10 -0400, Tom Lane wrote:
> > Out of curiosity I poked at this for a little while.
>
> Cool.
>
>
> > It doesn't appear to me that we leak much at all, at least not if you
> > are willing to take "still reachable" blocks as not-leaked.
>
> Well, I think for any sort of automated testing - which I think would be
> useful - we'd really need *no* leaks. I know that I get a few bleats
> whenever I forget to set --leak-check=no. It's also not just postgres
> itself, but some of the helper tools...
>
> And it's not just valgrind, also gcc/clang sanitizers...
>
>
> > What I found out is that we have a lot of issues that seem to devolve
> > to valgrind not being sure that a block is referenced.  I identified
> > two main causes of that:
> >
> > (1) We have a pointer, but it doesn't actually point right at the start
> > of the block.  A primary culprit here is lists of thingies that use the
> > slist and dlist infrastructure.  As an experiment, I moved the dlist_node
> > fields of some popular structs to the beginning, and verified that that
> > silences associated complaints.  I'm not sure that we want to insist on
> > put-the-link-first as policy (although if we did, it could provide some
> > notational savings perhaps).  However, unless someone knows of a way to
> > teach valgrind about this situation, there may be no other way to silence
> > those leakage complaints.  A secondary culprit is people randomly
> applying
> > CACHELINEALIGN or the like to a palloc'd address, so that the address we
> > have isn't pointing right at the block start.
>
> Hm, do you still have a backtrace / suppression for one of those? I
> didn't see any in a quick (*) serial installcheck I just ran. Or I
> wasn't able to pinpoint them to this issue.
>
>
> I think the run might have shown a genuine leak:
>
> ==2048803== 16 bytes in 1 blocks are definitely lost in loss record 139 of
> 906
> ==2048803==    at 0x89D2EA: palloc (mcxt.c:975)
> ==2048803==    by 0x2392D3: heap_beginscan (heapam.c:1198)
> ==2048803==    by 0x264E8F: table_beginscan_strat (tableam.h:918)
> ==2048803==    by 0x265994: systable_beginscan (genam.c:453)
> ==2048803==    by 0x83C2D1: SearchCatCacheMiss (catcache.c:1359)
> ==2048803==    by 0x83C197: SearchCatCacheInternal (catcache.c:1299)
> ==2048803==    by 0x83BE9A: SearchCatCache1 (catcache.c:1167)
> ==2048803==    by 0x85876A: SearchSysCache1 (syscache.c:1134)
> ==2048803==    by 0x84CDB3: RelationInitTableAccessMethod (relcache.c:1795)
> ==2048803==    by 0x84F807: RelationBuildLocalRelation (relcache.c:3554)
> ==2048803==    by 0x303C9D: heap_create (heap.c:395)
> ==2048803==    by 0x305790: heap_create_with_catalog (heap.c:1291)
> ==2048803==    by 0x41A327: DefineRelation (tablecmds.c:885)
> ==2048803==    by 0x6C96B6: ProcessUtilitySlow (utility.c:1131)
> ==2048803==    by 0x6C948A: standard_ProcessUtility (utility.c:1034)
> ==2048803==    by 0x6C865F: ProcessUtility (utility.c:525)
> ==2048803==    by 0x6C7409: PortalRunUtility (pquery.c:1159)
> ==2048803==    by 0x6C7636: PortalRunMulti (pquery.c:1305)
> ==2048803==    by 0x6C6B11: PortalRun (pquery.c:779)
> ==2048803==    by 0x6C05AB: exec_simple_query (postgres.c:1173)
> ==2048803==
> {
>    <insert_a_suppression_name_here>
>    Memcheck:Leak
>    match-leak-kinds: definite
>    fun:palloc
>    fun:heap_beginscan
>    fun:table_beginscan_strat
>    fun:systable_beginscan
>    fun:SearchCatCacheMiss
>    fun:SearchCatCacheInternal
>    fun:SearchCatCache1
>    fun:SearchSysCache1
>    fun:RelationInitTableAccessMethod
>    fun:RelationBuildLocalRelation
>    fun:heap_create
>    fun:heap_create_with_catalog
>    fun:DefineRelation
>    fun:ProcessUtilitySlow
>    fun:standard_ProcessUtility
>    fun:ProcessUtility
>    fun:PortalRunUtility
>    fun:PortalRunMulti
>    fun:PortalRun
>    fun:exec_simple_query
> }
>
> Since 56788d2156fc heap_beginscan() allocates
>         scan->rs_base.rs_private =
>                 palloc(sizeof(ParallelBlockTableScanWorkerData));
> in heap_beginscan(). But doesn't free it in heap_endscan().
>
> In most of the places heap scans are begun inside transient contexts,
> but not always. In the above trace for example
> RelationBuildLocalRelation switched to CacheMemoryContext, and nothing
> switched to something else.
>
> I'm a bit confused about the precise design of rs_private /
> ParallelBlockTableScanWorkerData, specifically why it's been added to
> TableScanDesc, instead of just adding it to HeapScanDesc? And why is it
> allocated unconditionally, instead of just for parallel scans?
>
>
> I don't think this is a false positive, even though it theoretically
> could be freed by resetting CacheMemoryContext (see below)?
>
>
> I saw a lot of false positives from autovacuum workers, because
> AutovacMemCxt is never deleted, and because table_toast_map is created
> in TopMemoryContext.  Adding an explicit
> MemoryContextDelete(AutovacMemCxt) and parenting table_toast_map in that
> shut that up.
>
>
> Which brings me to the question why allocations in CacheMemoryContext,
> AutovacMemCxt are considered to be "lost", even though they're still
> "reachable" via a context reset.  I think valgrind ends up treating
> memory allocated via memory contexts that still exist at process end as
> lost, regardless of being reachable via the the memory pool (from
> valgrinds view). Which I guess actually makes sense, for things like
> TopMemoryContext and CacheContext - anything not reachable by means
> other than a context reset is effectively lost for those.
>
> For autovac launcher / worker it seems like a sensible thing to just
> delete AutovacMemCxt.
>
>
>
> > (2) The only pointer to the start of a block is actually somewhere within
> > the block.  This is common in dynahash tables, where we allocate a slab
> > of entries in a single palloc and then thread them together.  Each entry
> > should have exactly one referencing pointer, but that pointer is more
> > likely to be elsewhere within the same palloc block than in the external
> > hash bucket array.  AFAICT, all cases except where the slab's first entry
> > is pointed to by a hash bucket pointer confuse valgrind to some extent.
> > I was able to hack around this by preventing dynahash from allocating
> > more than one hash entry per palloc, but I wonder if there's a better
> way.
>
> Hm. For me the number of leaks seem to stay the same with or without
> your changes related to this. Is this a USE_VALGRIND build?
>
> I'm using valgrind-3.16.1
>
>
> > Attached is a very crude hack, not meant for commit, that hacks things
> > up enough to greatly reduce the number of complaints with
> > "--leak-check=full".
> >
> > One thing I've failed to silence so far is a bunch of entries like
> >
> > ==00:00:03:56.088 3467702== 1,861 bytes in 67 blocks are definitely lost
> in loss record 1,290 of 1,418
> > ==00:00:03:56.088 3467702==    at 0x950650: MemoryContextAlloc
> (mcxt.c:827)
> > ==00:00:03:56.088 3467702==    by 0x951710: MemoryContextStrdup
> (mcxt.c:1179)
> > ==00:00:03:56.088 3467702==    by 0x91C86E: RelationInitIndexAccessInfo
> (relcache.c:1444)
> > ==00:00:03:56.088 3467702==    by 0x91DA9C: RelationBuildDesc
> (relcache.c:1200)
> >
> > which is complaining about the memory context identifiers for system
> > indexes' rd_indexcxt contexts.  Those are surely not being leaked in
> > any real sense.  I suspect that this has something to do with valgrind
> > not counting the context->ident fields as live pointers, but I don't
> > have enough valgrind-fu to fix that.
>
> Yea. I suspect it's related to the fact that we mark the memory as a
> valgrind mempool, I'll try to investigate.
>
>
> I do see a bunch of leaks bleats below fun:plpgsql_compile that I don't
> yet understand. E.g.
>
> ==2054558== 32 bytes in 1 blocks are definitely lost in loss record 284 of
> 913
> ==2054558==    at 0x89D389: palloc (mcxt.c:975)
> ==2054558==    by 0x518732: new_list (list.c:134)
> ==2054558==    by 0x518C0C: lappend (list.c:341)
> ==2054558==    by 0x83CAE7: SearchCatCacheList (catcache.c:1691)
> ==2054558==    by 0x859A9C: SearchSysCacheList (syscache.c:1447)
> ==2054558==    by 0x313192: FuncnameGetCandidates (namespace.c:975)
> ==2054558==    by 0x313D91: FunctionIsVisible (namespace.c:1450)
> ==2054558==    by 0x7C2891: format_procedure_extended (regproc.c:375)
> ==2054558==    by 0x7C27C3: format_procedure (regproc.c:324)
> ==2054558==    by 0xA7693E1: do_compile (pl_comp.c:348)
> ==2054558==    by 0xA769130: plpgsql_compile (pl_comp.c:224)
>
> and
>
> ==2054558== 30 bytes in 4 blocks are definitely lost in loss record 225 of
> 913
> ==2054558==    at 0x89D389: palloc (mcxt.c:975)
> ==2054558==    by 0x3ADDAE: downcase_identifier (scansup.c:52)
> ==2054558==    by 0x3ADD85: downcase_truncate_identifier (scansup.c:39)
> ==2054558==    by 0x3AB5E4: core_yylex (scan.l:1032)
> ==2054558==    by 0xA789B2D: internal_yylex (pl_scanner.c:321)
> ==2054558==    by 0xA7896E3: plpgsql_yylex (pl_scanner.c:152)
> ==2054558==    by 0xA780015: plpgsql_yyparse (pl_gram.c:1945)
> ==2054558==    by 0xA76A652: do_compile (pl_comp.c:788)
> ==2054558==    by 0xA769130: plpgsql_compile (pl_comp.c:224)
> ==2054558==    by 0xA78948F: plpgsql_validator (pl_handler.c:539)
>
> Based on the quick look I had (dinner is calling) I didn't yet
> understand how plpgsql_compile_tmp_cxt error handling works.
>
> Greetings,
>
> Andres Freund
>
>
> (*) or not so quick, I had to figure out why valgrind was so slow. It
> turned out that I had typed shared_buffers=32MB into
> shared_buffers=32GB...
>
>
>

  4. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-17T03:01:47Z

    Andres Freund <andres@anarazel.de> writes:
> On 2021-03-16 19:36:10 -0400, Tom Lane wrote:
>> It doesn't appear to me that we leak much at all, at least not if you
>> are willing to take "still reachable" blocks as not-leaked.

> Well, I think for any sort of automated testing - which I think would be
> useful - we'd really need *no* leaks.

That seems both unnecessary and impractical.  We have to consider that
everything-still-reachable is an OK final state.

> I think the run might have shown a genuine leak:

> ==2048803== 16 bytes in 1 blocks are definitely lost in loss record 139 of 906
> ==2048803==    at 0x89D2EA: palloc (mcxt.c:975)
> ==2048803==    by 0x2392D3: heap_beginscan (heapam.c:1198)
> ==2048803==    by 0x264E8F: table_beginscan_strat (tableam.h:918)
> ==2048803==    by 0x265994: systable_beginscan (genam.c:453)
> ==2048803==    by 0x83C2D1: SearchCatCacheMiss (catcache.c:1359)
> ==2048803==    by 0x83C197: SearchCatCacheInternal (catcache.c:1299)

I didn't see anything like that after applying the fixes I showed before.
There are a LOT of false positives from the fact that with our HEAD
code, valgrind believes that everything in the catalog caches and
most things in dynahash tables (including the relcache) are unreachable.

I'm not trying to claim there are no leaks anywhere, just that the amount
of noise from those issues swamps all the real problems.  I particularly
recommend not believing anything related to catcache or relcache if you
haven't applied that admittedly-hacky patch.

> Hm. For me the number of leaks seem to stay the same with or without
> your changes related to this. Is this a USE_VALGRIND build?

Yeah ...

> I do see a bunch of leaks bleats below fun:plpgsql_compile that I don't
> yet understand. E.g.

Those are probably a variant of what you were suggesting above, ie
plpgsql isn't terribly careful not to leak random stuff while building
a long-lived function parse tree.  It's supposed to use a temp context
for anything that might leak, but I suspect it's not thorough about it.
We could chase that sort of thing after we clean up the other problems.

			regards, tom lane

  5. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-17T03:23:42Z

    Andres Freund <andres@anarazel.de> writes:
> Hm. For me the number of leaks seem to stay the same with or without
> your changes related to this. Is this a USE_VALGRIND build?

Not sure how you arrived at that answer.  I attach two logs of individual
backends running with

--leak-check=full --track-origins=yes --read-var-info=yes --error-exitcode=0

The test scenario in both cases was just start up, run "select 2+2;",
quit.  The first one is before I'd made any of the changes shown
before, the second is after.

			regards, tom lane

  6. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-17T03:50:17Z

    Hi,

On Tue, Mar 16, 2021, at 20:01, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2021-03-16 19:36:10 -0400, Tom Lane wrote:
> >> It doesn't appear to me that we leak much at all, at least not if you
> >> are willing to take "still reachable" blocks as not-leaked.
> 
> > Well, I think for any sort of automated testing - which I think would be
> > useful - we'd really need *no* leaks.
> 
> That seems both unnecessary and impractical.  We have to consider that
> everything-still-reachable is an OK final state.

I don't consider "still reachable" a leak. Just definitely unreachable. And with a few tweaks that seems like we could achieve that?


> > I think the run might have shown a genuine leak:
> 
> > ==2048803== 16 bytes in 1 blocks are definitely lost in loss record 139 of 906
> > ==2048803==    at 0x89D2EA: palloc (mcxt.c:975)
> > ==2048803==    by 0x2392D3: heap_beginscan (heapam.c:1198)
> > ==2048803==    by 0x264E8F: table_beginscan_strat (tableam.h:918)
> > ==2048803==    by 0x265994: systable_beginscan (genam.c:453)
> > ==2048803==    by 0x83C2D1: SearchCatCacheMiss (catcache.c:1359)
> > ==2048803==    by 0x83C197: SearchCatCacheInternal (catcache.c:1299)
> 
> I didn't see anything like that after applying the fixes I showed before.
> There are a LOT of false positives from the fact that with our HEAD
> code, valgrind believes that everything in the catalog caches and
> most things in dynahash tables (including the relcache) are unreachable.

I think it's actually unreachable memory (unless you count resetting the cache context), based on manually tracing the code... I'll try to repro.


> > I do see a bunch of leaks bleats below fun:plpgsql_compile that I don't
> > yet understand. E.g.
> 
> Those are probably a variant of what you were suggesting above, ie
> plpgsql isn't terribly careful not to leak random stuff while building
> a long-lived function parse tree.  It's supposed to use a temp context
> for anything that might leak, but I suspect it's not thorough about it.

What I meant was that I didn't understand how there's not a leak danger when compilation fails halfway through, given that the context in question is below TopMemoryContext and that I didn't see a relevant TRY block. But that probably there is something cleaning it up that I didn't see.

Andres

  7. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-17T04:01:55Z

    "Andres Freund" <andres@anarazel.de> writes:
> On Tue, Mar 16, 2021, at 20:01, Tom Lane wrote:
>> That seems both unnecessary and impractical.  We have to consider that
>> everything-still-reachable is an OK final state.

> I don't consider "still reachable" a leak. Just definitely unreachable.

OK, we're in violent agreement then -- I must've misread what you wrote.

>>> I think the run might have shown a genuine leak:

>> I didn't see anything like that after applying the fixes I showed before.

> I think it's actually unreachable memory (unless you count resetting the cache context), based on manually tracing the code... I'll try to repro.

I agree that having to reset CacheContext is not something we
should count as "still reachable", and I'm pretty sure that the
existing valgrind infrastructure doesn't count it that way.

As for the particular point about ParallelBlockTableScanWorkerData,
I agree with your question to David about why that's in TableScanDesc
not HeapScanDesc, but I can't get excited about it not being freed in
heap_endscan.  That's mainly because I do not believe that anything as
complex as a heap or indexscan should be counted on to be zero-leakage.
The right answer is to not do such operations in long-lived contexts.
So if we're running such a thing while switched into CacheContext,
*that* is the bug, not that heap_endscan didn't free this particular
allocation.

			regards, tom lane

  8. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-17T05:57:18Z

    Hi,

On 2021-03-16 20:50:17 -0700, Andres Freund wrote:
> What I meant was that I didn't understand how there's not a leak
> danger when compilation fails halfway through, given that the context
> in question is below TopMemoryContext and that I didn't see a relevant
> TRY block. But that probably there is something cleaning it up that I
> didn't see.

Looks like it's an actual leak:

postgres[2058957][1]=# DO $do$BEGIN CREATE OR REPLACE FUNCTION foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;END;$$;^C
postgres[2058957][1]=# SELECT count(*), SUM(total_bytes) FROM pg_backend_memory_contexts WHERE name = 'PL/pgSQL function';
┌───────┬────────┐
│ count │  sum   │
├───────┼────────┤
│     0 │ (null) │
└───────┴────────┘
(1 row)

Time: 1.666 ms
postgres[2058957][1]=# CREATE OR REPLACE FUNCTION foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;END;$$;
ERROR:  42601: syntax error at or near "frakbar"
LINE 1: ...ON foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;EN...
                                                             ^
LOCATION:  scanner_yyerror, scan.l:1176
Time: 5.463 ms
postgres[2058957][1]=# CREATE OR REPLACE FUNCTION foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;END;$$;
ERROR:  42601: syntax error at or near "frakbar"
LINE 1: ...ON foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;EN...
                                                             ^
LOCATION:  scanner_yyerror, scan.l:1176
Time: 1.223 ms
postgres[2058957][1]=# CREATE OR REPLACE FUNCTION foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;END;$$;
ERROR:  42601: syntax error at or near "frakbar"
LINE 1: ...ON foo() RETURNS VOID LANGUAGE plpgsql AS $$BEGIN frakbar;EN...
                                                             ^
LOCATION:  scanner_yyerror, scan.l:1176
Time: 1.194 ms
postgres[2058957][1]=# SELECT count(*), SUM(total_bytes) FROM pg_backend_memory_contexts WHERE name = 'PL/pgSQL function';
┌───────┬───────┐
│ count │  sum  │
├───────┼───────┤
│     3 │ 24576 │
└───────┴───────┘
(1 row)

Something like

DO $do$ BEGIN FOR i IN 1 .. 10000 LOOP BEGIN EXECUTE $cf$CREATE OR REPLACE FUNCTION foo() RETURNS VOID LANGUAGE plpgsql AS $f$BEGIN frakbar; END;$f$;$cf$; EXCEPTION WHEN others THEN END; END LOOP; END;$do$;

will show the leak visible in top too (albeit slowly - a more
complicated statement will leak more quickly I think).


postgres[2059268][1]=# SELECT count(*), SUM(total_bytes) FROM pg_backend_memory_contexts WHERE name = 'PL/pgSQL function';
┌───────┬──────────┐
│ count │   sum    │
├───────┼──────────┤
│ 10000 │ 81920000 │
└───────┴──────────┘
(1 row)

The leak appears to be not new, I see it in 9.6 as well. This seems like
a surprisingly easy to trigger leak...


Looks like there's something else awry. The above DO statement takes
2.2s on an 13 assert build, but 32s on a master assert build. Spending a
lot of time doing dependency lookups:

-   94.62%     0.01%  postgres  postgres            [.] CreateFunction
   - 94.61% CreateFunction
      - 94.56% ProcedureCreate
         - 89.68% deleteDependencyRecordsFor
            - 89.38% systable_getnext
               - 89.33% index_getnext_slot
                  - 56.00% index_fetch_heap
                     + 54.64% table_index_fetch_tuple
                       0.09% heapam_index_fetch_tuple
                  + 28.53% index_getnext_tid
                    2.77% ItemPointerEquals
                    0.10% table_index_fetch_tuple
                    0.09% btgettuple
                 0.03% index_getnext_tid

1000 iterations: 521ms
1000 iterations: 533ms
2000 iterations: 1670ms
3000 iterations: 3457ms
3000 iterations: 3457ms
10000 iterations: 31794ms

The quadratic seeming nature made me wonder if someone broke killtuples
in this situation. And it seem that someone was me, in 623a9ba . We need
to bump xactCompletionCount in the subxid abort case as well...

Greetings,

Andres Freund

  9. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-17T14:16:44Z

    Andres Freund <andres@anarazel.de> writes:
> On 2021-03-16 20:50:17 -0700, Andres Freund wrote:
>> What I meant was that I didn't understand how there's not a leak
>> danger when compilation fails halfway through, given that the context
>> in question is below TopMemoryContext and that I didn't see a relevant
>> TRY block. But that probably there is something cleaning it up that I
>> didn't see.

> Looks like it's an actual leak:

Yeah, I believe that.  On the other hand, I'm not sure that such cases
represent any real problem for production usage.  I'm inclined to focus
on non-error scenarios first.

(Having said that, we probably have the ability to fix such things
relatively painlessly now, by reparenting an initially-temporary
context once we're done parsing.)

Meanwhile, I'm still trying to understand why valgrind is whining
about the rd_indexcxt identifier strings.  AFAICS it shouldn't.

			regards, tom lane

  10. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-17T15:15:43Z

    Hi,

On Wed, Mar 17, 2021, at 07:16, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2021-03-16 20:50:17 -0700, Andres Freund wrote:
> Meanwhile, I'm still trying to understand why valgrind is whining
> about the rd_indexcxt identifier strings.  AFAICS it shouldn't.

I found a way around that late last night. Need to mark the context itself as an allocation. But I made a mess on the way to that and need to clean the patch up before sending it (and need to drop my girlfriend off first).

Andres

  11. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-17T18:15:31Z

    Hi,

(really need to fix my mobile phone mail program to keep the CC list...)

On 2021-03-17 08:15:43 -0700, Andres Freund wrote:
> On Wed, Mar 17, 2021, at 07:16, Tom Lane wrote:
> > Andres Freund <andres@anarazel.de> writes:
> > > On 2021-03-16 20:50:17 -0700, Andres Freund wrote:
> > Meanwhile, I'm still trying to understand why valgrind is whining
> > about the rd_indexcxt identifier strings.  AFAICS it shouldn't.
> 
> I found a way around that late last night. Need to mark the context
> itself as an allocation. But I made a mess on the way to that and need
> to clean the patch up before sending it (and need to drop my
> girlfriend off first).

Unfortunately I didn't immediately find a way to do this while keeping
the MEMPOOL_CREATE/DESTROY in mcxt.c. The attached patch moves the pool
creation into the memory context implementations, "allocates" the
context itself as part of that pool, and changes the reset
implementation from MEMPOOL_DESTROY + MEMPOOL_CREATE to instead do
MEMPOOL_TRIM. That leaves the memory context itself valid (and thus
tracking ->ident etc), but marks all the other memory as freed.

This is just a first version, it probably needs more work, and
definitely a few comments...

After this, your changes, and the previously mentioned fixes, I get far
fewer false positives. Also found a crash / memory leak in pgstat.c due
to the new replication slot stats, but I'll start a separate thread.


There are a few leak warnings around guc.c that look like they might be
real, not false positives, and thus a bit concerning. Looks like several
guc check hooks don't bother to free the old *extra before allocating a
new one.


I suspect we might get better results from valgrind, not just for leaks
but also undefined value tracking, if we changed the way we represent
pools to utilize VALGRIND_MEMPOOL_METAPOOL |
VALGRIND_MEMPOOL_AUTO_FREE. E.g. aset.c would associate AllocBlock using
VALGRIND_MEMPOOL_ALLOC and then mcxt.c would use
VALGRIND_MALLOCLIKE_BLOCK for the individual chunk allocation.

https://www.valgrind.org/docs/manual/mc-manual.html#mc-manual.mempools


I played with naming the allocations underlying aset.c using
VALGRIND_CREATE_BLOCK(block, strlen(context->name), context->name).
That does produce better undefined-value warnings, but it seems that
e.g. the leak detector doen't have that information around. Nor does it
seem to be usable for use-afte-free. At least the latter likely because
I had to VALGRIND_DISCARD by that point...

Greetings,

Andres Freund

  12. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-17T22:07:36Z

    Andres Freund <andres@anarazel.de> writes:
>> I found a way around that late last night. Need to mark the context
>> itself as an allocation. But I made a mess on the way to that and need
>> to clean the patch up before sending it (and need to drop my
>> girlfriend off first).

> Unfortunately I didn't immediately find a way to do this while keeping
> the MEMPOOL_CREATE/DESTROY in mcxt.c. The attached patch moves the pool
> creation into the memory context implementations, "allocates" the
> context itself as part of that pool, and changes the reset
> implementation from MEMPOOL_DESTROY + MEMPOOL_CREATE to instead do
> MEMPOOL_TRIM. That leaves the memory context itself valid (and thus
> tracking ->ident etc), but marks all the other memory as freed.

Huh, interesting.  I wonder why that makes the ident problem go away?
I'd supposed that valgrind would see the context headers as ordinary
memory belonging to the global "malloc" pool, so that any pointers
inside them ought to be considered valid.

Anyway, I don't have a problem with rearranging the responsibility
like this.  It gives the individual allocators more freedom to do
odd stuff, at the cost of very minor duplication of valgrind calls.

I agree we need more comments -- would you like me to have a go at
writing them?

One thing I was stewing over last night is that a MemoryContextReset
will mess up any context identifier assigned with
MemoryContextCopyAndSetIdentifier.  I'd left that as a problem to
fix later, because we don't currently have a need to reset contexts
that use copied identifiers.  But that assumption obviously will bite
us someday, so maybe now is a good time to think about it.

The very simplest fix would be to allocate non-constant idents with
malloc; which'd require adding a flag to track whether context->ident
needs to be free()d.  We have room for another bool near the top of
struct MemoryContextData (and at some point we could turn those
bool fields into a flags word).  The only real cost here is one
more free() while destroying a labeled context, which is probably
negligible.

Other ideas are possible but they seem to require getting the individual
mcxt methods involved, and I doubt it's worth the complexity.

> There are a few leak warnings around guc.c that look like they might be
> real, not false positives, and thus a bit concerning. Looks like several
> guc check hooks don't bother to free the old *extra before allocating a
> new one.

I'll take a look, but I'm pretty certain that guc.c, not the hooks, is
responsible for freeing those.  Might be another case of valgrind not
understanding what's happening.

> I suspect we might get better results from valgrind, not just for leaks
> but also undefined value tracking, if we changed the way we represent
> pools to utilize VALGRIND_MEMPOOL_METAPOOL |
> VALGRIND_MEMPOOL_AUTO_FREE.

Don't really see why that'd help?  I mean, it could conceivably help
catch bugs in the allocators themselves, but I don't follow the argument
that it'd improve anything else.  Defined is defined, as far as I can
tell from the valgrind manual.

			regards, tom lane

  13. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-18T00:26:56Z

    Hi,

On 2021-03-17 18:07:36 -0400, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> >> I found a way around that late last night. Need to mark the context
> >> itself as an allocation. But I made a mess on the way to that and need
> >> to clean the patch up before sending it (and need to drop my
> >> girlfriend off first).
> 
> > Unfortunately I didn't immediately find a way to do this while keeping
> > the MEMPOOL_CREATE/DESTROY in mcxt.c. The attached patch moves the pool
> > creation into the memory context implementations, "allocates" the
> > context itself as part of that pool, and changes the reset
> > implementation from MEMPOOL_DESTROY + MEMPOOL_CREATE to instead do
> > MEMPOOL_TRIM. That leaves the memory context itself valid (and thus
> > tracking ->ident etc), but marks all the other memory as freed.
> 
> Huh, interesting.  I wonder why that makes the ident problem go away?
> I'd supposed that valgrind would see the context headers as ordinary
> memory belonging to the global "malloc" pool, so that any pointers
> inside them ought to be considered valid.


I'm didn't quite understand either at the time of writing the change. It
just seemed the only explanation for some the behaviour I was seeing, so
I tried it. Just to be initially be rebuffed due to errors when
accessing the recycled sets...

I spent a bit of time looking at valgrind, and it looks to be explicit
behaviour:

memcheck/mc_leakcheck.c

static MC_Chunk**
find_active_chunks(Int* pn_chunks)
{
   // Our goal is to construct a set of chunks that includes every
   // mempool chunk, and every malloc region that *doesn't* contain a
   // mempool chunk.
...
   // Then we loop over the mempool tables. For each chunk in each
   // pool, we set the entry in the Bool array corresponding to the
   // malloc chunk containing the mempool chunk.
   VG_(HT_ResetIter)(MC_(mempool_list));
   while ( (mp = VG_(HT_Next)(MC_(mempool_list))) ) {
      VG_(HT_ResetIter)(mp->chunks);
      while ( (mc = VG_(HT_Next)(mp->chunks)) ) {

         // We'll need to record this chunk.
         n_chunks++;

         // Possibly invalidate the malloc holding the beginning of this chunk.
         m = find_chunk_for(mc->data, mallocs, n_mallocs);
         if (m != -1 && malloc_chunk_holds_a_pool_chunk[m] == False) {
            tl_assert(n_chunks > 0);
            n_chunks--;
            malloc_chunk_holds_a_pool_chunk[m] = True;
         }

I think that means it explicitly ignores the entire malloced allocation
whenever there's *any* mempool chunk in it, instead considering only the
mempool chunks. So once aset allocats something in the init block, the
context itself is ignored for leak checking purposes. But that wouldn't
be the case if we didn't have the init block...

I guess that makes sense, but would definitely be nice to have had
documented...



> Anyway, I don't have a problem with rearranging the responsibility
> like this.  It gives the individual allocators more freedom to do
> odd stuff, at the cost of very minor duplication of valgrind calls.

Yea, similar.


> I agree we need more comments -- would you like me to have a go at
> writing them?

Gladly!


> One thing I was stewing over last night is that a MemoryContextReset
> will mess up any context identifier assigned with
> MemoryContextCopyAndSetIdentifier.

Valgrind should catch such problems. Not having the danger would be
better, of course.

We could also add an assertion at reset time that the identifier isn't
in the current context.


> The very simplest fix would be to allocate non-constant idents with
> malloc; which'd require adding a flag to track whether context->ident
> needs to be free()d.  We have room for another bool near the top of
> struct MemoryContextData (and at some point we could turn those
> bool fields into a flags word).  The only real cost here is one
> more free() while destroying a labeled context, which is probably
> negligible.

Hm. A separate malloc()/free() could conceivably actually show up in
profiles at some point.

What if we instead used that flag to indicate that MemoryContextReset()
needs to save the identifier? Then any cost would only be paid if the
context is actually reset.


> > There are a few leak warnings around guc.c that look like they might be
> > real, not false positives, and thus a bit concerning. Looks like several
> > guc check hooks don't bother to free the old *extra before allocating a
> > new one.
> 
> I'll take a look, but I'm pretty certain that guc.c, not the hooks, is
> responsible for freeing those.

Yea, I had misattributed the leak to the callbacks. One of the things I
saw definitely is a leak: if call_string_check_hook() ereport(ERRORs)
the guc_strdup() of newval->stringval is lost.

There's another set of them that seems to be related to paralellism. But
I've not hunted it down yet.

I think it might be worth adding a VALGRIND_DO_CHANGED_LEAK_CHECK() at
the end of a transaction or such? That way it'd not be quite as hard to
pinpoint the source of a leak to individual statements as it is right
now.


> Might be another case of valgrind not understanding what's happening.

Those allocations seem very straightforward, plain malloc/free that is
referenced by a pointer to the start of the allocation. So that doesn't
seem very likely?


> > I suspect we might get better results from valgrind, not just for leaks
> > but also undefined value tracking, if we changed the way we represent
> > pools to utilize VALGRIND_MEMPOOL_METAPOOL |
> > VALGRIND_MEMPOOL_AUTO_FREE.
> 
> Don't really see why that'd help?  I mean, it could conceivably help
> catch bugs in the allocators themselves, but I don't follow the argument
> that it'd improve anything else.  Defined is defined, as far as I can
> tell from the valgrind manual.

I think it might improve the attribution of some use-after-free errors
to the memory context. Looks like it also might reduce the cost of
running valgrind a bit.

Greetings,

Andres Freund

  14. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-18T01:30:48Z

    Andres Freund <andres@anarazel.de> writes:
> On 2021-03-17 18:07:36 -0400, Tom Lane wrote:
>> Huh, interesting.  I wonder why that makes the ident problem go away?

> I spent a bit of time looking at valgrind, and it looks to be explicit
> behaviour:
>
>    // Our goal is to construct a set of chunks that includes every
>    // mempool chunk, and every malloc region that *doesn't* contain a
>    // mempool chunk.

Ugh.

> I guess that makes sense, but would definitely be nice to have had
> documented...

Indeed.  So this started happening to us when we merged the aset
header with its first allocation block.

>>> There are a few leak warnings around guc.c that look like they might be
>>> real, not false positives, and thus a bit concerning. Looks like several
>>> guc check hooks don't bother to free the old *extra before allocating a
>>> new one.

>> I'll take a look, but I'm pretty certain that guc.c, not the hooks, is
>> responsible for freeing those.

I believe I've just tracked down the cause of that.  Those errors
are (as far as I've seen) only happening in parallel workers, and
the reason is this gem in RestoreGUCState:

	/* See comment at can_skip_gucvar(). */
	for (i = 0; i < num_guc_variables; i++)
		if (!can_skip_gucvar(guc_variables[i]))
			InitializeOneGUCOption(guc_variables[i]);

where InitializeOneGUCOption zeroes out that GUC variable, causing
it to lose track of any allocations it was responsible for.

At minimum, somebody didn't understand the difference between "initialize"
and "reset".  But I suspect we could just nuke this loop altogether.
I've not yet tried to grok the comment that purports to justify it,
but I fail to see why it'd ever be useful to drop values inherited
from the postmaster.

			regards, tom lane

  15. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-18T02:05:19Z

    Hi,

On 2021-03-17 21:30:48 -0400, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2021-03-17 18:07:36 -0400, Tom Lane wrote:
> >> Huh, interesting.  I wonder why that makes the ident problem go away?
> 
> > I spent a bit of time looking at valgrind, and it looks to be explicit
> > behaviour:
> >
> >    // Our goal is to construct a set of chunks that includes every
> >    // mempool chunk, and every malloc region that *doesn't* contain a
> >    // mempool chunk.
> 
> Ugh.
> 
> > I guess that makes sense, but would definitely be nice to have had
> > documented...
> 
> Indeed.  So this started happening to us when we merged the aset
> header with its first allocation block.

Yea.

I have the feeling that valgrinds error detection capability in our
codebase used to be higher too. I wonder if that could be related
somehow. Or maybe it's just a figment of my imagination.


> I believe I've just tracked down the cause of that.  Those errors
> are (as far as I've seen) only happening in parallel workers, and
> the reason is this gem in RestoreGUCState:
> 
> 	/* See comment at can_skip_gucvar(). */
> 	for (i = 0; i < num_guc_variables; i++)
> 		if (!can_skip_gucvar(guc_variables[i]))
> 			InitializeOneGUCOption(guc_variables[i]);
> 
> where InitializeOneGUCOption zeroes out that GUC variable, causing
> it to lose track of any allocations it was responsible for.

Ouch. At least it's a short lived issue rather than something permanently
leaking memory on every SIGHUP...



> At minimum, somebody didn't understand the difference between "initialize"
> and "reset".  But I suspect we could just nuke this loop altogether.
> I've not yet tried to grok the comment that purports to justify it,
> but I fail to see why it'd ever be useful to drop values inherited
> from the postmaster.

I can't really make sense of it either. I think it may be trying to
restore the GUC state to what it would have been in postmaster,
disregarding all the settings that were set as part of PostgresInit()
etc?

Greetings,

Andres Freund

  16. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-18T02:33:59Z

    Andres Freund <andres@anarazel.de> writes:
> On 2021-03-17 21:30:48 -0400, Tom Lane wrote:
>> I believe I've just tracked down the cause of that.  Those errors
>> are (as far as I've seen) only happening in parallel workers, and
>> the reason is this gem in RestoreGUCState: ...

> Ouch. At least it's a short lived issue rather than something permanently
> leaking memory on every SIGHUP...

Yeah.  This leak is really insignificant in practice, although I'm
suspicious that randomly init'ing GUCs like this might have semantic
issues that we've not detected yet.

>> I've not yet tried to grok the comment that purports to justify it,
>> but I fail to see why it'd ever be useful to drop values inherited
>> from the postmaster.

> I can't really make sense of it either. I think it may be trying to
> restore the GUC state to what it would have been in postmaster,
> disregarding all the settings that were set as part of PostgresInit()
> etc?

At least in a non-EXEC_BACKEND build, the most reliable way to reproduce
the postmaster's settings is to do nothing whatsoever.  And I think the
same is true for EXEC_BACKEND, really, because the guc.c subsystem is
responsible for restoring what would have been the inherited-via-fork
settings.  So I'm really not sure what this is on about, and I'm too
tired to try to figure it out tonight.

In other news, I found that there's a genuine leak in
RelationBuildLocalRelation: RelationInitTableAccessMethod
was added in a spot where CurrentMemoryContext is CacheMemoryContext,
which is bad because it does a syscache lookup that can lead to
a table access which can leak some memory.  Seems easy to fix though.

The plpgsql situation looks like a mess.  As a short-term answer,
I'm inclined to recommend adding an exclusion that will ignore anything
allocated within plpgsql_compile().  Doing better will require a fair
amount of rewriting.  (Although I suppose we could also consider adding
an on_proc_exit callback that runs through and frees all the function
cache entries.)

			regards, tom lane

  17. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-18T03:02:50Z

    Hi,

On 2021-03-17 00:01:55 -0400, Tom Lane wrote:
> As for the particular point about ParallelBlockTableScanWorkerData,
> I agree with your question to David about why that's in TableScanDesc
> not HeapScanDesc, but I can't get excited about it not being freed in
> heap_endscan. That's mainly because I do not believe that anything as
> complex as a heap or indexscan should be counted on to be zero-leakage.
> The right answer is to not do such operations in long-lived contexts.
> So if we're running such a thing while switched into CacheContext,
> *that* is the bug, not that heap_endscan didn't free this particular
> allocation.

I agree that it's a bad idea to do scans in non-transient contexts. It
does however seems like there's a number of places that do...

I added the following hacky definition of "permanent" contexts

/*
 * NB: Only for assertion use.
 *
 * TopMemoryContext itself obviously is permanent. Treat CacheMemoryContext
 * and all its children as permanent too.
 *
 * XXX: Might be worth adding this as an explicit flag on the context?
 */
bool
MemoryContextIsPermanent(MemoryContext c)
{
	if (c == TopMemoryContext)
		return true;

	while (c)
	{
		if (c == CacheMemoryContext)
			return true;
		c = c->parent;
	}

	return false;
}

and checked that the CurrentMemoryContext is not permanent in
SearchCatCacheInternal() and systable_beginscan(). Hit a number of
times.

The most glaring case is the RelationInitTableAccessMethod() call in
RelationBuildLocalRelation(). Seems like the best fix is to just move
the MemoryContextSwitchTo() to just before the
RelationInitTableAccessMethod().  Although I wonder if we shouldn't go
further, and move it to much earlier, somewhere after the rd_rel
allocation.

There's plenty other hits, but I think I should get back to working on
making the shared memory stats patch committable. I really wouldn't want
it to slip yet another year.

But I think it might make sense to add a flag indicating contexts that
shouldn't be used for non-transient data. Seems like we fairly regularly
have "bugs" around this?

Greetings,

Andres Freund

  18. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-18T03:15:36Z

    On 2021-03-17 22:33:59 -0400, Tom Lane wrote:
> >> I've not yet tried to grok the comment that purports to justify it,
> >> but I fail to see why it'd ever be useful to drop values inherited
> >> from the postmaster.
> 
> > I can't really make sense of it either. I think it may be trying to
> > restore the GUC state to what it would have been in postmaster,
> > disregarding all the settings that were set as part of PostgresInit()
> > etc?
> 
> At least in a non-EXEC_BACKEND build, the most reliable way to reproduce
> the postmaster's settings is to do nothing whatsoever.  And I think the
> same is true for EXEC_BACKEND, really, because the guc.c subsystem is
> responsible for restoring what would have been the inherited-via-fork
> settings.  So I'm really not sure what this is on about, and I'm too
> tired to try to figure it out tonight.

The restore thing runs after we've already set and initialized GUCs,
including things like user/database default GUCs. Is see things like

==2251779== 4,560 bytes in 1 blocks are definitely lost in loss record 383 of 406
==2251779==    at 0x483877F: malloc (vg_replace_malloc.c:307)
==2251779==    by 0x714A45: ConvertTimeZoneAbbrevs (datetime.c:4556)
==2251779==    by 0x88DE95: load_tzoffsets (tzparser.c:465)
==2251779==    by 0x88511D: check_timezone_abbreviations (guc.c:11565)
==2251779==    by 0x884633: call_string_check_hook (guc.c:11232)
==2251779==    by 0x87CB57: parse_and_validate_value (guc.c:7012)
==2251779==    by 0x87DD5F: set_config_option (guc.c:7630)
==2251779==    by 0x88397F: ProcessGUCArray (guc.c:10784)
==2251779==    by 0x32BCCF: ApplySetting (pg_db_role_setting.c:256)
==2251779==    by 0x874CA2: process_settings (postinit.c:1163)
==2251779==    by 0x874A0B: InitPostgres (postinit.c:1048)
==2251779==    by 0x60129A: BackgroundWorkerInitializeConnectionByOid (postmaster.c:5681)
==2251779==    by 0x2BB283: ParallelWorkerMain (parallel.c:1374)
==2251779==    by 0x5EBA6A: StartBackgroundWorker (bgworker.c:864)
==2251779==    by 0x6014FE: do_start_bgworker (postmaster.c:5802)
==2251779==    by 0x6018D2: maybe_start_bgworkers (postmaster.c:6027)
==2251779==    by 0x600811: sigusr1_handler (postmaster.c:5190)
==2251779==    by 0x4DD513F: ??? (in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so)
==2251779==    by 0x556E865: select (select.c:41)
==2251779==    by 0x5FC0CB: ServerLoop (postmaster.c:1700)
==2251779==    by 0x5FBA68: PostmasterMain (postmaster.c:1408)
==2251779==    by 0x4F8BFD: main (main.c:209)

The BackgroundWorkerInitializeConnectionByOid() in that trace is before
the RestoreGUCState() later in ParallelWorkerMain().  But that doesn't
really explain the approach.


> In other news, I found that there's a genuine leak in
> RelationBuildLocalRelation: RelationInitTableAccessMethod
> was added in a spot where CurrentMemoryContext is CacheMemoryContext,
> which is bad because it does a syscache lookup that can lead to
> a table access which can leak some memory.  Seems easy to fix though.

Yea, that's the one I was talking about re
ParallelBlockTableScanWorkerData not being freed. While I think we
should also add that pfree, I think you're right, and we shouldn't do
RelationInitTableAccessMethod() while in CacheMemoryContext.


> The plpgsql situation looks like a mess.  As a short-term answer,
> I'm inclined to recommend adding an exclusion that will ignore anything
> allocated within plpgsql_compile().  Doing better will require a fair
> amount of rewriting.  (Although I suppose we could also consider adding
> an on_proc_exit callback that runs through and frees all the function
> cache entries.)

The error variant of this one seems like it might actually be a
practically relevant leak? As well as increasing memory usage for
compiled plpgsql functions unnecessarily, of course. The latter would be
good to fix, but the former seems like it might be a practical issue for
poolers and the like?

So I think we should do at least the reparenting thing to address that?

Greetings,

Andres Freund

  19. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-18T03:21:47Z

    Andres Freund <andres@anarazel.de> writes:
> The most glaring case is the RelationInitTableAccessMethod() call in
> RelationBuildLocalRelation(). Seems like the best fix is to just move
> the MemoryContextSwitchTo() to just before the
> RelationInitTableAccessMethod().  Although I wonder if we shouldn't go
> further, and move it to much earlier, somewhere after the rd_rel
> allocation.

Yeah, same thing I did locally.  Not sure if it's worth working harder.

> There's plenty other hits, but I think I should get back to working on
> making the shared memory stats patch committable. I really wouldn't want
> it to slip yet another year.

+1, so far there's little indication that we're finding any serious leaks
here.  Might be best to set it all aside till there's more time.

			regards, tom lane

  20. Re: Getting better results from valgrind leak tracking

    Tom Lane <tgl@sss.pgh.pa.us> — 2021-03-18T21:51:28Z

    I wrote:
> Andres Freund <andres@anarazel.de> writes:
>> There's plenty other hits, but I think I should get back to working on
>> making the shared memory stats patch committable. I really wouldn't want
>> it to slip yet another year.

> +1, so far there's little indication that we're finding any serious leaks
> here.  Might be best to set it all aside till there's more time.

Well, I failed to resist the temptation to keep poking at this issue,
mainly because I felt that it'd be a good idea to make sure we'd gotten
our arms around all of the detectable issues, even if we choose not to
fix them right away.  The attached patch, combined with your preceding
memory context patch, eliminates all but a very small number of the leak
complaints in the core regression tests.

The remaing leak warnings that I see are:

1. WaitForReplicationWorkerAttach leaks the BackgroundWorkerHandle it's
passed.  I'm not sure which function should clean that up, but in any
case it's only 16 bytes one time in one process, so it's hardly exciting.

2. There's lots of leakage in text search dictionary initialization
functions.  This is hard to get around completely, because the API for
those functions has them being called in the dictionary's long-lived
context.  In any case, the leaks are not large (modulo comments below),
and they would get cleaned up if the dictionary cache were thrown away.

3. partition_prune.sql repeatably produces this warning:

==00:00:44:39.764 3813570== 32,768 bytes in 1 blocks are possibly lost in loss record 2,084 of 2,096
==00:00:44:39.764 3813570==    at 0x4C30F0B: malloc (vg_replace_malloc.c:307)
==00:00:44:39.764 3813570==    by 0x94315A: AllocSetAlloc (aset.c:941)
==00:00:44:39.764 3813570==    by 0x94B52F: MemoryContextAlloc (mcxt.c:804)
==00:00:44:39.764 3813570==    by 0x8023DA: LockAcquireExtended (lock.c:845)
==00:00:44:39.764 3813570==    by 0x7FFC7E: LockRelationOid (lmgr.c:116)
==00:00:44:39.764 3813570==    by 0x5CB89F: findDependentObjects (dependency.c:962)
==00:00:44:39.764 3813570==    by 0x5CBA66: findDependentObjects (dependency.c:1060)
==00:00:44:39.764 3813570==    by 0x5CBA66: findDependentObjects (dependency.c:1060)
==00:00:44:39.764 3813570==    by 0x5CCB72: performMultipleDeletions (dependency.c:409)
==00:00:44:39.764 3813570==    by 0x66F574: RemoveRelations (tablecmds.c:1395)
==00:00:44:39.764 3813570==    by 0x81C986: ProcessUtilitySlow.isra.8 (utility.c:1698)
==00:00:44:39.764 3813570==    by 0x81BCF2: standard_ProcessUtility (utility.c:1034)

which evidently is warning that some LockMethodLocalHash entry is losing
track of its lockOwners array.  But I sure don't see how that could
happen, nor why it'd only happen in this test.  Could this be a false
report?

As you can see from the patch's additions to src/tools/valgrind.supp,
I punted on the issues around pl/pgsql's function-compile-time leaks.
We know that's an issue, but again the leaks are fairly small and
they are confined within function cache entries, so I'm not sure
how hard we should work on that.

(An idea for silencing both this and the dictionary leak warnings is
to install an on-proc-exit callback to drop the cached objects'
contexts.)

Anyway, looking through the patch, I found several non-cosmetic issues:

* You were right to suspect that there was residual leakage in guc.c's
handling of error cases.  ProcessGUCArray and call_string_check_hook
are both guilty of leaking malloc'd strings if an error in a proposed
GUC setting is detected.

* I still haven't tried to wrap my brain around the question of what
RestoreGUCState really needs to be doing.  I have, however, found that
check-world passes just fine with the InitializeOneGUCOption calls
diked out entirely, so that's what's in this patch.

* libpqwalreceiver.c leaks a malloc'd error string when
libpqrcv_check_conninfo detects an erroneous conninfo string.

* spell.c leaks a compiled regular expression if an ispell dictionary
cache entry is dropped.  I fixed this by adding a memory context reset
callback to release the regex.  This is potentially a rather large
leak, if the regex is complex (though typically it wouldn't be).

* BuildEventTriggerCache leaks working storage into
EventTriggerCacheContext.

* Likewise, load_domaintype_info leaks working storage into
a long-lived cache context.

* RelationDestroyRelation leaks rd_statlist; the patch that added
that failed to emulate the rd_indexlist prototype very well.

* As previously noted, RelationInitTableAccessMethod causes leaks.

* I made some effort to remove easily-removable leakage in
lookup_ts_dictionary_cache itself, although given the leaks in
its callees, this isn't terribly exciting.

I am suspicious that there's something still not quite right in the
memory context changes, because I noticed that the sanity_check.sql
test (and no other ones) complained about row_description_context being
leaked.  I realized that the warning was because my compiler optimizes
away the row_description_context static variable altogether, leaving no
pointer to the context behind.  I hacked around that in this patch by
marking that variable volatile.  However, that explanation just begs
the question of why every run didn't show the same warning.  I suppose
that valgrind was considering the context to be referenced by some
child or sibling context pointer, but if that's the explanation then
we should never have seen the warning.  I'm forced to the conclusion
that valgrind is counting some but not all child/sibling context
pointers, which sure seems like a bug.  Maybe we need the two-level-
mempool mechanism after all to get that to work better.

Anyway, I think we need to commit and even back-patch the portion
of the attached changes that are in
* libpqwalreceiver.c
* spell.h / spell.c
* relcache.c
* guc.c (except the quick hack in RestoreGUCState)
Those are all genuine leaks that are in places where they could be
repeated and thus potentially add up to something significant.

There's a weaker case for applying the changes in evtcache.c,
ts_cache.c, and typcache.c.  Those are all basically leaving some cruft
behind in a long-lived cache entry.  But the cruft isn't huge and it
would be recovered at cache flush, so I'm not convinced it amounts to a
real-world problem.

The rest of this is either working around valgrind shortcomings or
jumping through a hoop to convince it that some data structure that's
still around at exit is still referenced.  Maybe we should commit some
of it under "#ifdef USE_VALGRIND" tests.  I really want to find some
other answer than moving the dlist_node fields, though.

Comments?

			regards, tom lane

  21. Re: Getting better results from valgrind leak tracking

    David Rowley <dgrowleyml@gmail.com> — 2021-03-28T22:48:47Z

    On Wed, 17 Mar 2021 at 15:31, Andres Freund <andres@anarazel.de> wrote:
> I'm a bit confused about the precise design of rs_private /
> ParallelBlockTableScanWorkerData, specifically why it's been added to
> TableScanDesc, instead of just adding it to HeapScanDesc? And why is it
> allocated unconditionally, instead of just for parallel scans?

That's a good point. In hindsight, I didn't spend enough effort
questioning that design in the original patch.  I see now that the
rs_private field makes very little sense as we can just store what's
private to heapam in HeapScanDescData.

I've done that in the attached.  I added the
ParallelBlockTableScanWorkerData as a pointer field in
HeapScanDescData and change it so we only allocate memory for it for
just parallel scans.  The field is left as NULL for non-parallel
scans.

I've also added a pfree in heap_endscan() to free the memory when the
pointer is not NULL. I'm hoping that'll fix the valgrind warning, but
I've not run it to check.

David

  22. Re: Getting better results from valgrind leak tracking

    Andres Freund <andres@anarazel.de> — 2021-03-29T17:38:16Z

    Hi,

On 2021-03-29 11:48:47 +1300, David Rowley wrote:
> I've done that in the attached.  I added the
> ParallelBlockTableScanWorkerData as a pointer field in
> HeapScanDescData and change it so we only allocate memory for it for
> just parallel scans.  The field is left as NULL for non-parallel
> scans.

LGTM.

> I've also added a pfree in heap_endscan() to free the memory when the
> pointer is not NULL. I'm hoping that'll fix the valgrind warning, but
> I've not run it to check.

Cool. I think that's a good thing to do. The leak itself should already
be fixed, and was more my fault...

commit 415ffdc2205e209b6a73fb42a3fdd6e57e16c7b2
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date:   2021-03-18 20:50:56 -0400

    Don't run RelationInitTableAccessMethod in a long-lived context.


Greetings,

Andres Freund

  23. Re: Getting better results from valgrind leak tracking

    David Rowley <dgrowleyml@gmail.com> — 2021-03-29T21:18:11Z

    On Tue, 30 Mar 2021 at 06:38, Andres Freund <andres@anarazel.de> wrote:
> On 2021-03-29 11:48:47 +1300, David Rowley wrote:
> > I've done that in the attached.  I added the
> > ParallelBlockTableScanWorkerData as a pointer field in
> > HeapScanDescData and change it so we only allocate memory for it for
> > just parallel scans.  The field is left as NULL for non-parallel
> > scans.
>
> LGTM.

Thanks for having a look.

Pushed.

David