Re: error_severity of brin work item - Mailing list pgsql-hackers

From Justin Pryzby
Subject Re: error_severity of brin work item
Date
Msg-id 20201113181121.GS30691@telsasoft.com
Whole thread Raw
In response to Re: error_severity of brin work item  (Alvaro Herrera <alvherre@alvh.no-ip.org>)
Responses Re: error_severity of brin work item  (Justin Pryzby <pryzby@telsasoft.com>)
List pgsql-hackers
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

Attachment

pgsql-hackers by date:

Previous
From: Soumyadeep Chakraborty
Date:
Subject: Table AM modifications to accept column projection lists
Next
From: Tom Lane
Date:
Subject: Re: [PATCH] Support negative indexes in split_part