error_severity of brin work item

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
11 messages Options
Reply | Threaded
Open this post in threaded view
|

error_severity of brin work item

Justin Pryzby
I saw a bunch of these in my logs:

log_time | 2020-10-25 22:59:45.619-07
database |
left     | could not open relation with OID 292103095
left     | processing work entry for relation "ts.child.alarms_202010_alarm_clear_time_idx"

Those happen following a REINDEX job on that index.

I think that should be more like an INFO message, since that's what vacuum does
(vacuum_open_relation), and a queued work item is even more likely to hit a
dropped relation.  It's easy to hit by setting autovacuum_naptime=1 and looping
around REINDEX CONCURRENTLY while updating a table.

Autovacuum is queueing work items for later:

src/backend/postmaster/autovacuum.c-            switch (workitem->avw_type)
src/backend/postmaster/autovacuum.c-            {
src/backend/postmaster/autovacuum.c-                    case AVW_BRINSummarizeRange:
src/backend/postmaster/autovacuum.c:                            DirectFunctionCall2(brin_summarize_range,
src/backend/postmaster/autovacuum.c-                                                                    ObjectIdGetDatum(workitem->avw_relation),
src/backend/postmaster/autovacuum.c-                                                                    Int64GetDatum((int64) workitem->avw_blockNumber));
src/backend/postmaster/autovacuum.c-                            break;

And if the index is missing:

brin_summarize_range(PG_FUNCTION_ARGS)
|        /*
|         * We must lock table before index to avoid deadlocks.  However, if the
|         * passed indexoid isn't an index then IndexGetRelation() will fail.
|         * Rather than emitting a not-very-helpful error message, postpone
|         * complaining, expecting that the is-it-an-index test below will fail.
|         */
|        heapoid = IndexGetRelation(indexoid, true);
|        if (OidIsValid(heapoid))
|                heapRel = table_open(heapoid, ShareUpdateExclusiveLock);
|        else
|                heapRel = NULL;
|
|        indexRel = index_open(indexoid, ShareUpdateExclusiveLock);

table_open is succcessful and then index_open fails.  (I thought locks would
have prevented that ?)

Justin


Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Álvaro Herrera
On 2020-Nov-13, Justin Pryzby wrote:

> I saw a bunch of these in my logs:
>
> log_time | 2020-10-25 22:59:45.619-07
> database |
> left     | could not open relation with OID 292103095
> left     | processing work entry for relation "ts.child.alarms_202010_alarm_clear_time_idx"
>
> Those happen following a REINDEX job on that index.
>
> I think that should be more like an INFO message, since that's what vacuum does
> (vacuum_open_relation), and a queued work item is even more likely to hit a
> dropped relation.
Ah, interesting.  Yeah, I agree this is a bug.  I think it can be fixed
by using try_relation_open() on the index; if that returns NULL, discard
the work item.

Does this patch solve the problem?


brin-workitems.patch (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Justin Pryzby
On Fri, Nov 13, 2020 at 01:39:31PM -0300, Alvaro Herrera wrote:

> On 2020-Nov-13, Justin Pryzby wrote:
>
> > I saw a bunch of these in my logs:
> >
> > log_time | 2020-10-25 22:59:45.619-07
> > database |
> > left     | could not open relation with OID 292103095
> > left     | processing work entry for relation "ts.child.alarms_202010_alarm_clear_time_idx"
> >
> > Those happen following a REINDEX job on that index.
> >
> > I think that should be more like an INFO message, since that's what vacuum does
> > (vacuum_open_relation), and a queued work item is even more likely to hit a
> > dropped relation.
>
> Ah, interesting.  Yeah, I agree this is a bug.  I think it can be fixed
> by using try_relation_open() on the index; if that returns NULL, discard
> the work item.
>
> Does this patch solve the problem?
Your patch didn't actually say "try_relation_open", so didn't work.
But it does works if I do that, and close the table.

I tested like:

pryzbyj=# ALTER SYSTEM SET backtrace_functions='try_relation_open,relation_open';
pryzbyj=# ALTER SYSTEM SET autovacuum_naptime=3; SELECT pg_reload_conf();
pryzbyj=# CREATE TABLE tt AS SELECT generate_series(1,9999)i;
pryzbyj=# CREATE INDEX ON tt USING brin(i) WITH(autosummarize,pages_per_range=1);
pryzbyj=# \! while :; do psql -h /tmp -qc 'SET client_min_messages=info' -c 'REINDEX INDEX CONCURRENTLY tt_i_idx'; done&

-- run this 5-10 times and hit the "...was not recorded" message, which for
-- whatever reason causes the race condition involving work queue
pryzbyj=# UPDATE tt SET i=1+i;

2020-11-13 11:50:46.093 CST [30687] ERROR:  could not open relation with OID 1110882
2020-11-13 11:50:46.093 CST [30687] CONTEXT:  processing work entry for relation "pryzbyj.public.tt_i_idx"
2020-11-13 11:50:46.093 CST [30687] BACKTRACE:
        postgres: autovacuum worker pryzbyj(+0xb9ce8) [0x55acf2af0ce8]
        postgres: autovacuum worker pryzbyj(index_open+0xb) [0x55acf2bab59b]
        postgres: autovacuum worker pryzbyj(brin_summarize_range+0x8f) [0x55acf2b5b5bf]
        postgres: autovacuum worker pryzbyj(DirectFunctionCall2Coll+0x62) [0x55acf2f40372]
        ...

--
Justin

v2-0001-error_severity-of-brin-work-item.patch (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Justin Pryzby
On Fri, Nov 13, 2020 at 12:11:21PM -0600, Justin Pryzby wrote:

> On Fri, Nov 13, 2020 at 01:39:31PM -0300, Alvaro Herrera wrote:
> > On 2020-Nov-13, Justin Pryzby wrote:
> >
> > > I saw a bunch of these in my logs:
> > >
> > > log_time | 2020-10-25 22:59:45.619-07
> > > database |
> > > left     | could not open relation with OID 292103095
> > > left     | processing work entry for relation "ts.child.alarms_202010_alarm_clear_time_idx"
> > >
> > > Those happen following a REINDEX job on that index.
> > >
> > > I think that should be more like an INFO message, since that's what vacuum does
> > > (vacuum_open_relation), and a queued work item is even more likely to hit a
> > > dropped relation.
> >
> > Ah, interesting.  Yeah, I agree this is a bug.  I think it can be fixed
> > by using try_relation_open() on the index; if that returns NULL, discard
> > the work item.
> >
> > Does this patch solve the problem?
>
> Your patch didn't actually say "try_relation_open", so didn't work.
> But it does works if I do that, and close the table.
That patch broke the case that a non-index is passed, which I addressed here.

I wondered if the function should return NULL in those cases, but it seems to
be "impossible".

v3-0001-Avoid-errors-in-brin-summarization.patch (2K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Álvaro Herrera
On 2020-Nov-19, Justin Pryzby wrote:

> On Fri, Nov 13, 2020 at 12:11:21PM -0600, Justin Pryzby wrote:

> > Your patch didn't actually say "try_relation_open", so didn't work.
> > But it does works if I do that, and close the table.

Thanks for fixing and testing.

> That patch broke the case that a non-index is passed, which I addressed here.

Hmm, I think the reaction to that should be the same as before, so
rather than return 0, the patch should raise the same error that
index_open() would.



Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Justin Pryzby
On Thu, Nov 19, 2020 at 03:15:21PM -0300, Alvaro Herrera wrote:

> On 2020-Nov-19, Justin Pryzby wrote:
>
> > On Fri, Nov 13, 2020 at 12:11:21PM -0600, Justin Pryzby wrote:
>
> > > Your patch didn't actually say "try_relation_open", so didn't work.
> > > But it does works if I do that, and close the table.
>
> Thanks for fixing and testing.
>
> > That patch broke the case that a non-index is passed, which I addressed here.
>
> Hmm, I think the reaction to that should be the same as before, so
> rather than return 0, the patch should raise the same error that
> index_open() would.
The resulting logic is not very clear and requires a lot of commentary..

BTW I saw that in tablecmds.c, RangeVarCallbackForAttachIndex() does this:

        if (classform->relkind != RELKIND_PARTITIONED_INDEX &&
                classform->relkind != RELKIND_INDEX)
                ereport(ERROR,
                                (errcode(ERRCODE_INVALID_OBJECT_DEFINITION),
                                 errmsg("\"%s\" is not an index", rv->relname)));

Is it wrong to use ERRCODE_INVALID_OBJECT_DEFINITION ?
Most other places say ERRCODE_WRONG_OBJECT_TYPE

Likewise, transformPartitionCmd() in parse_utilcmd.c:
                (errcode(ERRCODE_INVALID_OBJECT_DEFINITION),
                 errmsg("\"%s\" is not a partitioned table",
                                RelationGetRelationName(parentRel))));

--
Justin

0001-Avoid-errors-in-brin-summarization.patch (2K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Álvaro Herrera
I think this formulation (attached v3) has fewer moving parts.

However, now that I did that, I wonder if this is really the best
approach to solve this problem.  Maybe instead of doing this at the BRIN
level, it should be handled at the autovac level, by having the worker
copy the work-item to local memory and remove it from the shared list as
soon as it is in progress.  That way, if *any* error occurs while trying
to execute it, it will go away instead of being retried for all
eternity.

Preliminary patch for that attached as autovacuum-workitem.patch.

I would propose to clean that up to apply instead of your proposed fix.

v3-0001-Avoid-errors-in-brin-summarization.patch (2K) Download Attachment
autovacuum-workitem.patch (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Justin Pryzby
On Mon, Nov 23, 2020 at 04:39:57PM -0300, Alvaro Herrera wrote:

> I think this formulation (attached v3) has fewer moving parts.
>
> However, now that I did that, I wonder if this is really the best
> approach to solve this problem.  Maybe instead of doing this at the BRIN
> level, it should be handled at the autovac level, by having the worker
> copy the work-item to local memory and remove it from the shared list as
> soon as it is in progress.  That way, if *any* error occurs while trying
> to execute it, it will go away instead of being retried for all
> eternity.
>
> Preliminary patch for that attached as autovacuum-workitem.patch.
>
> I would propose to clean that up to apply instead of your proposed fix.

I don't know why you said it would be retried for eternity ?
I think the perform_work_item() TRY/CATCH avoids that.

Also .. I think your idea doesn't solve my issue, that REINDEX CONCURRENTLY is
causing vacuum to leave errors in my logs.

I check that the first patch avoids the issue and the 2nd one does not.

--
Justin


Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Álvaro Herrera
The more I look at this, the less I like it.  This would set a precedent
that any action that can be initiated from an autovac work-item has a
requirement of silently being discarded when it referenced a
non-existant relation.

I'd rather have the code that drops the index go through the list of
work-items and delete those that reference that relation.

I'm not sure if this is something that ought to be done in index_drop();
One objection might be that if the drop is rolled back, the work-items
are lost.  It's the easiest, though; and work-items are supposed to be
lossy anyway, and vacuum would fix the lack of summarization eventually.
So, not pretty, but not all that bad.  (Hopefully rolled-back drops are
not all that common.)


Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Justin Pryzby
On Mon, Nov 30, 2020 at 08:47:32PM -0300, Alvaro Herrera wrote:
> The more I look at this, the less I like it.  This would set a precedent
> that any action that can be initiated from an autovac work-item has a
> requirement of silently being discarded when it referenced a
> non-existant relation.

My original request was to change to INFO, which is what vacuum proper does at
vacuum_open_relation().  I realize that still means that new work item handlers
would have to do the LockOid, try_open dance - maybe it could be factored out.

I noticed this on multiple servers immediate after changing a nagios script to
look for all ERRORs (rather than a specific list of log_messages) and for a
longer time period.

> I'd rather have the code that drops the index go through the list of
> work-items and delete those that reference that relation.
>
> I'm not sure if this is something that ought to be done in index_drop();
> One objection might be that if the drop is rolled back, the work-items
> are lost.

Should it be done in an AtCommit hook or something like that ?

--
Justin


Reply | Threaded
Open this post in threaded view
|

Re: error_severity of brin work item

Álvaro Herrera
On 2020-Nov-30, Justin Pryzby wrote:

> On Mon, Nov 30, 2020 at 08:47:32PM -0300, Alvaro Herrera wrote:
> > The more I look at this, the less I like it.  This would set a precedent
> > that any action that can be initiated from an autovac work-item has a
> > requirement of silently being discarded when it referenced a
> > non-existant relation.
>
> My original request was to change to INFO, which is what vacuum proper does at
> vacuum_open_relation().  I realize that still means that new work item handlers
> would have to do the LockOid, try_open dance - maybe it could be factored out.

As I understand, INFO is not well suited to messages that are not going
to the client.  Anyway, my point is about the contortions that are
needed to support the case, rather than what exactly do we do when it
happens.

Retrospectively, it's strange that this problem (what happens when
indexes with pending work-items are dropped) hadn't manifested.  It
seems a pretty obvious one.

> > I'd rather have the code that drops the index go through the list of
> > work-items and delete those that reference that relation.
> >
> > I'm not sure if this is something that ought to be done in index_drop();
> > One objection might be that if the drop is rolled back, the work-items
> > are lost.
>
> Should it be done in an AtCommit hook or something like that ?

I didn't like this idea much on first read, on extensibility grounds,
but perhaps it's not so bad because we can generalize it whenever
there's pressure to add a second type of work-item (*if* that ever
happens).

I suppose the idea is that index_drop saves the index OID when a BRIN
index with autosummarization=on is dropped, and then the
AtCommit_WorkItems() call scans the items list and drops those that
match any OIDs in the list.  (It does require to be mindful of subxact
aborts, of course.)