pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feeddsa_allocate() faliure
60+ messages / 11 participants
[nested] [flat]
* dsa_allocate() faliure
@ 2018-01-29 16:19 Rick Otten <rottenwindfish@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Rick Otten @ 2018-01-29 16:19 UTC (permalink / raw)
To: pgsql-performance
I'm wondering if there is anything I can tune in my PG 10.1 database to
avoid these errors:
$ psql -f failing_query.sql
psql:failing_query.sql:46: ERROR: dsa_allocate could not find 7 free pages
CONTEXT: parallel worker
I tried throttling back the number of parallel workers to just 2, that
didn't help.
The query is joining two views that each have 50 or so underlying queries,
unioned, in them. Unfortunately due to an invalid index, it is sequence
scanning some of the tables. I can't fix the indexes until a few create
materialized view commands that are currently running (and have been
running for 6 days) finish or I kill them, because they are holding a lock
that is blocking any attempt to reindex.
So that leaves me looking for some tunable (hopefully one that doesn't
require a restart) which will fix this by adding sufficient resources to
the system to allow the dsa_allocate() to find enough (contiguous?) pages.
My system seems to have plenty of extra capacity.
There was a thread on pghackers in December where someone else was seeing a
similar error, but couldn't reproduce it consistently. I've run the above
query hundreds of times over the last 24 hours, but just the one fails when
I select just the right parameters - and fails every time I run it with
those parameters.
In that thread someone speculated it had to do with running many parallel
bitmap heap scans in one query. I count 98 in the query plan.
I'm hoping there is a "magic X tunable" which I just need to bump up a
little to let queries like this run without the fatal failure.
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-01-29 16:37 Tom Lane <tgl@sss.pgh.pa.us>
parent: Rick Otten <rottenwindfish@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Tom Lane @ 2018-01-29 16:37 UTC (permalink / raw)
To: Rick Otten <rottenwindfish@gmail.com>; +Cc: pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@enterprisedb.com>
Rick Otten <rottenwindfish@gmail.com> writes:
> I'm wondering if there is anything I can tune in my PG 10.1 database to
> avoid these errors:
> $ psql -f failing_query.sql
> psql:failing_query.sql:46: ERROR: dsa_allocate could not find 7 free pages
> CONTEXT: parallel worker
Hmm. There's only one place in the source code that emits that message
text:
/*
* Ask the free page manager for a run of pages. This should always
* succeed, since both get_best_segment and make_new_segment should
* only return a non-NULL pointer if it actually contains enough
* contiguous freespace. If it does fail, something in our backend
* private state is out of whack, so use FATAL to kill the process.
*/
if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
elog(FATAL,
"dsa_allocate could not find %zu free pages", npages);
Now maybe that comment is being unreasonably optimistic, but it sure
appears that this is supposed to be a can't-happen case, in which case
you've found a bug.
cc'ing the DSA authors for comment.
regards, tom lane
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-01-29 20:52 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-01-29 20:52 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Rick Otten <rottenwindfish@gmail.com>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
On Tue, Jan 30, 2018 at 5:37 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Rick Otten <rottenwindfish@gmail.com> writes:
>> I'm wondering if there is anything I can tune in my PG 10.1 database to
>> avoid these errors:
>
>> $ psql -f failing_query.sql
>> psql:failing_query.sql:46: ERROR: dsa_allocate could not find 7 free pages
>> CONTEXT: parallel worker
>
> Hmm. There's only one place in the source code that emits that message
> text:
>
> /*
> * Ask the free page manager for a run of pages. This should always
> * succeed, since both get_best_segment and make_new_segment should
> * only return a non-NULL pointer if it actually contains enough
> * contiguous freespace. If it does fail, something in our backend
> * private state is out of whack, so use FATAL to kill the process.
> */
> if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
> elog(FATAL,
> "dsa_allocate could not find %zu free pages", npages);
>
> Now maybe that comment is being unreasonably optimistic, but it sure
> appears that this is supposed to be a can't-happen case, in which case
> you've found a bug.
This is probably the bug fixed here:
https://www.postgresql.org/message-id/E1eQzIl-0004wM-K3%40gemulon.postgresql.org
That was back patched, so 10.2 will contain the fix. The bug was not
in dsa.c itself, but in the parallel query code that mixed up DSA
areas, corrupting them. The problem comes up when the query plan has
multiple Gather nodes (and a particular execution pattern) -- is that
the case here, in the EXPLAIN output? That seems plausible given the
description of a 50-branch UNION. The only workaround until 10.2
would be to reduce max_parallel_workers_per_gather to 0 to prevent
parallelism completely for this query.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-01-29 21:35 Rick Otten <rottenwindfish@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Rick Otten @ 2018-01-29 21:35 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
If I do a "set max_parallel_workers_per_gather=0;" before I run the query
in that session, it runs just fine.
If I set it to 2, the query dies with the dsa_allocate error.
I'll use that as a work around until 10.2 comes out. Thanks! I have
something that will help.
On Mon, Jan 29, 2018 at 3:52 PM, Thomas Munro <thomas.munro@enterprisedb.com
> wrote:
> On Tue, Jan 30, 2018 at 5:37 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> > Rick Otten <rottenwindfish@gmail.com> writes:
> >> I'm wondering if there is anything I can tune in my PG 10.1 database to
> >> avoid these errors:
> >
> >> $ psql -f failing_query.sql
> >> psql:failing_query.sql:46: ERROR: dsa_allocate could not find 7 free
> pages
> >> CONTEXT: parallel worker
> >
> > Hmm. There's only one place in the source code that emits that message
> > text:
> >
> > /*
> > * Ask the free page manager for a run of pages. This should
> always
> > * succeed, since both get_best_segment and make_new_segment
> should
> > * only return a non-NULL pointer if it actually contains enough
> > * contiguous freespace. If it does fail, something in our
> backend
> > * private state is out of whack, so use FATAL to kill the
> process.
> > */
> > if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
> > elog(FATAL,
> > "dsa_allocate could not find %zu free pages", npages);
> >
> > Now maybe that comment is being unreasonably optimistic, but it sure
> > appears that this is supposed to be a can't-happen case, in which case
> > you've found a bug.
>
> This is probably the bug fixed here:
>
> https://www.postgresql.org/message-id/E1eQzIl-0004wM-K3%
> 40gemulon.postgresql.org
>
> That was back patched, so 10.2 will contain the fix. The bug was not
> in dsa.c itself, but in the parallel query code that mixed up DSA
> areas, corrupting them. The problem comes up when the query plan has
> multiple Gather nodes (and a particular execution pattern) -- is that
> the case here, in the EXPLAIN output? That seems plausible given the
> description of a 50-branch UNION. The only workaround until 10.2
> would be to reduce max_parallel_workers_per_gather to 0 to prevent
> parallelism completely for this query.
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-05-23 04:10 Sand Stone <sand.m.stone@gmail.com>
parent: Rick Otten <rottenwindfish@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sand Stone @ 2018-05-23 04:10 UTC (permalink / raw)
To: Rick Otten <rottenwindfish@gmail.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
>>dsa_allocate could not find 7 free pages
I just this error message again on all of my worker nodes (I am using
Citus 7.4 rel). The PG core is my own build of release_10_stable
(10.4) out of GitHub on Ubuntu.
What's the best way to debug this? I am running pre-production tests
for the next few days, so I could gather info. if necessary (I cannot
pinpoint a query to repro this yet, as we have 10K queries running
concurrently).
On Mon, Jan 29, 2018 at 1:35 PM, Rick Otten <rottenwindfish@gmail.com> wrote:
> If I do a "set max_parallel_workers_per_gather=0;" before I run the query in
> that session, it runs just fine.
> If I set it to 2, the query dies with the dsa_allocate error.
>
> I'll use that as a work around until 10.2 comes out. Thanks! I have
> something that will help.
>
>
> On Mon, Jan 29, 2018 at 3:52 PM, Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
>>
>> On Tue, Jan 30, 2018 at 5:37 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> > Rick Otten <rottenwindfish@gmail.com> writes:
>> >> I'm wondering if there is anything I can tune in my PG 10.1 database to
>> >> avoid these errors:
>> >
>> >> $ psql -f failing_query.sql
>> >> psql:failing_query.sql:46: ERROR: dsa_allocate could not find 7 free
>> >> pages
>> >> CONTEXT: parallel worker
>> >
>> > Hmm. There's only one place in the source code that emits that message
>> > text:
>> >
>> > /*
>> > * Ask the free page manager for a run of pages. This should
>> > always
>> > * succeed, since both get_best_segment and make_new_segment
>> > should
>> > * only return a non-NULL pointer if it actually contains enough
>> > * contiguous freespace. If it does fail, something in our
>> > backend
>> > * private state is out of whack, so use FATAL to kill the
>> > process.
>> > */
>> > if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
>> > elog(FATAL,
>> > "dsa_allocate could not find %zu free pages", npages);
>> >
>> > Now maybe that comment is being unreasonably optimistic, but it sure
>> > appears that this is supposed to be a can't-happen case, in which case
>> > you've found a bug.
>>
>> This is probably the bug fixed here:
>>
>>
>> https://www.postgresql.org/message-id/E1eQzIl-0004wM-K3%40gemulon.postgresql.org
>>
>> That was back patched, so 10.2 will contain the fix. The bug was not
>> in dsa.c itself, but in the parallel query code that mixed up DSA
>> areas, corrupting them. The problem comes up when the query plan has
>> multiple Gather nodes (and a particular execution pattern) -- is that
>> the case here, in the EXPLAIN output? That seems plausible given the
>> description of a 50-branch UNION. The only workaround until 10.2
>> would be to reduce max_parallel_workers_per_gather to 0 to prevent
>> parallelism completely for this query.
>>
>> --
>> Thomas Munro
>> http://www.enterprisedb.com
>
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-05-23 04:44 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Sand Stone <sand.m.stone@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-05-23 04:44 UTC (permalink / raw)
To: Sand Stone <sand.m.stone@gmail.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
On Wed, May 23, 2018 at 4:10 PM, Sand Stone <sand.m.stone@gmail.com> wrote:
>>>dsa_allocate could not find 7 free pages
> I just this error message again on all of my worker nodes (I am using
> Citus 7.4 rel). The PG core is my own build of release_10_stable
> (10.4) out of GitHub on Ubuntu.
At which commit ID?
All of your worker nodes... so this happened at the same time or at
different times? I don't know much about Citus -- do you mean that
these were separate PostgreSQL clusters, and they were all running the
same query and they all crashed like this?
> What's the best way to debug this? I am running pre-production tests
> for the next few days, so I could gather info. if necessary (I cannot
> pinpoint a query to repro this yet, as we have 10K queries running
> concurrently).
Any chance of an EXPLAIN plan for the query that crashed like this?
Do you know if it's using multiple Gather[Merge] nodes and parallel
bitmap heap scans? Was it a regular backend process or a parallel
worker process (or a Citus worker process, if that is a thing?) that
raised the error?
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-05-23 14:06 Sand Stone <sand.m.stone@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sand Stone @ 2018-05-23 14:06 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
>> At which commit ID?
83fcc615020647268bb129cbf86f7661feee6412 (5/6)
>>do you mean that these were separate PostgreSQL clusters, and they were all running the same query and they all crashed like this?
A few worker nodes, a table is hash partitioned by "aTable.did" by
Citus, and further partitioned by PG10 by time range on field "ts". As
far as I could tell, Citus just does a query rewrite, and execute the
same type of queries to all nodes.
>>so this happened at the same time or at different times?
At the same time. The queries are simple count and sum queries, here
is the relevant part from one of the worker nodes:
2018-05-23 01:24:01.492 UTC [130536] ERROR: dsa_allocate could not
find 7 free pages
2018-05-23 01:24:01.492 UTC [130536] CONTEXT: parallel worker
STATEMENT: COPY (SELECT count(1) AS count, sum(worker_column_1) AS
sum FROM (SELECT subquery.avg AS worker_column_1 FROM (SELECT
aTable.did, avg((aTable.sum OPERATOR(pg_catalog./)
(aTable.count)::double precision)) AS avg FROM public.aTable_102117
aTable WHERE ((aTable.ts OPERATOR(pg_catalog.>=) '2018-04-25
00:00:00+00'::timestamp with time zone) AND (aTable.ts
OPERATOR(pg_catalog.<=) '2018-04-30 00:00:00+00'::timestamp with time
zone) AND (aTable.v OPERATOR(pg_catalog.=) 12345)) GROUP BY
aTable.did) subquery) worker_subquery) TO STDOUT WITH (FORMAT binary)
>> a parallel worker process
I think this is more of PG10 parallel bg worker issue. I don't think
Citus just lets each worker PG server do its own planning.
I will try to do more experiments about this, and see if there is any
specific query to cause the parallel query execution to fail. As far
as I can tell, the level of concurrency triggered this issue. That is
executing 10s of queries as shown on the worker nodes, depending on
the stats, the PG10 core may or may not spawn more bg workers.
Thanks for your time!
On Tue, May 22, 2018 at 9:44 PM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> On Wed, May 23, 2018 at 4:10 PM, Sand Stone <sand.m.stone@gmail.com> wrote:
>>>>dsa_allocate could not find 7 free pages
>> I just this error message again on all of my worker nodes (I am using
>> Citus 7.4 rel). The PG core is my own build of release_10_stable
>> (10.4) out of GitHub on Ubuntu.
>
> At which commit ID?
>
> All of your worker nodes... so this happened at the same time or at
> different times? I don't know much about Citus -- do you mean that
> these were separate PostgreSQL clusters, and they were all running the
> same query and they all crashed like this?
>
>> What's the best way to debug this? I am running pre-production tests
>> for the next few days, so I could gather info. if necessary (I cannot
>> pinpoint a query to repro this yet, as we have 10K queries running
>> concurrently).
>
> Any chance of an EXPLAIN plan for the query that crashed like this?
> Do you know if it's using multiple Gather[Merge] nodes and parallel
> bitmap heap scans? Was it a regular backend process or a parallel
> worker process (or a Citus worker process, if that is a thing?) that
> raised the error?
>
> --
> Thomas Munro
> http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-08-15 20:32 Sand Stone <sand.m.stone@gmail.com>
parent: Sand Stone <sand.m.stone@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sand Stone @ 2018-08-15 20:32 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
Just as a follow up. I tried the parallel execution again (in a stress
test environment). Now the crash seems gone. I will keep an eye on
this for the next few weeks.
My theory is that the Citus cluster created and shut down a lot of TCP
connections between coordinator and workers. If running on untuned
Linux machines, the TCP ports might run out.
Of course, I am using "newer" PG10 bits and Citus7.5 this time.
On Wed, May 23, 2018 at 7:06 AM Sand Stone <sand.m.stone@gmail.com> wrote:
>
> >> At which commit ID?
> 83fcc615020647268bb129cbf86f7661feee6412 (5/6)
>
> >>do you mean that these were separate PostgreSQL clusters, and they were all running the same query and they all crashed like this?
> A few worker nodes, a table is hash partitioned by "aTable.did" by
> Citus, and further partitioned by PG10 by time range on field "ts". As
> far as I could tell, Citus just does a query rewrite, and execute the
> same type of queries to all nodes.
>
> >>so this happened at the same time or at different times?
> At the same time. The queries are simple count and sum queries, here
> is the relevant part from one of the worker nodes:
> 2018-05-23 01:24:01.492 UTC [130536] ERROR: dsa_allocate could not
> find 7 free pages
> 2018-05-23 01:24:01.492 UTC [130536] CONTEXT: parallel worker
> STATEMENT: COPY (SELECT count(1) AS count, sum(worker_column_1) AS
> sum FROM (SELECT subquery.avg AS worker_column_1 FROM (SELECT
> aTable.did, avg((aTable.sum OPERATOR(pg_catalog./)
> (aTable.count)::double precision)) AS avg FROM public.aTable_102117
> aTable WHERE ((aTable.ts OPERATOR(pg_catalog.>=) '2018-04-25
> 00:00:00+00'::timestamp with time zone) AND (aTable.ts
> OPERATOR(pg_catalog.<=) '2018-04-30 00:00:00+00'::timestamp with time
> zone) AND (aTable.v OPERATOR(pg_catalog.=) 12345)) GROUP BY
> aTable.did) subquery) worker_subquery) TO STDOUT WITH (FORMAT binary)
>
>
> >> a parallel worker process
> I think this is more of PG10 parallel bg worker issue. I don't think
> Citus just lets each worker PG server do its own planning.
>
> I will try to do more experiments about this, and see if there is any
> specific query to cause the parallel query execution to fail. As far
> as I can tell, the level of concurrency triggered this issue. That is
> executing 10s of queries as shown on the worker nodes, depending on
> the stats, the PG10 core may or may not spawn more bg workers.
>
> Thanks for your time!
>
>
>
>
>
> On Tue, May 22, 2018 at 9:44 PM, Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
> > On Wed, May 23, 2018 at 4:10 PM, Sand Stone <sand.m.stone@gmail.com> wrote:
> >>>>dsa_allocate could not find 7 free pages
> >> I just this error message again on all of my worker nodes (I am using
> >> Citus 7.4 rel). The PG core is my own build of release_10_stable
> >> (10.4) out of GitHub on Ubuntu.
> >
> > At which commit ID?
> >
> > All of your worker nodes... so this happened at the same time or at
> > different times? I don't know much about Citus -- do you mean that
> > these were separate PostgreSQL clusters, and they were all running the
> > same query and they all crashed like this?
> >
> >> What's the best way to debug this? I am running pre-production tests
> >> for the next few days, so I could gather info. if necessary (I cannot
> >> pinpoint a query to repro this yet, as we have 10K queries running
> >> concurrently).
> >
> > Any chance of an EXPLAIN plan for the query that crashed like this?
> > Do you know if it's using multiple Gather[Merge] nodes and parallel
> > bitmap heap scans? Was it a regular backend process or a parallel
> > worker process (or a Citus worker process, if that is a thing?) that
> > raised the error?
> >
> > --
> > Thomas Munro
> > http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-08-15 22:42 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Sand Stone <sand.m.stone@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-08-15 22:42 UTC (permalink / raw)
To: Sand Stone <sand.m.stone@gmail.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
On Thu, Aug 16, 2018 at 8:32 AM, Sand Stone <sand.m.stone@gmail.com> wrote:
> Just as a follow up. I tried the parallel execution again (in a stress
> test environment). Now the crash seems gone. I will keep an eye on
> this for the next few weeks.
Thanks for the report. That's great news, but it'd be good to
understand why it was happening.
> My theory is that the Citus cluster created and shut down a lot of TCP
> connections between coordinator and workers. If running on untuned
> Linux machines, the TCP ports might run out.
I'm not sure how that's relevant, unless perhaps it causes executor
nodes to be invoked in a strange sequence that commit fd7c0fa7 didn't
fix? I wonder if there could be something different about the control
flow with custom scans, or something about the way Citus worker nodes
invoke plan fragments, or some error path that I failed to consider...
It's a clue that all of your worker nodes reliably crashed at the same
time on the same/similar queries (presumably distributed query
fragments for different shards), making it seem more like a
common-or-garden bug rather than some kind of timing-based heisenbug.
If you ever manage to reproduce it, an explain plan and a back trace
would be very useful.
> Of course, I am using "newer" PG10 bits and Citus7.5 this time.
Hmm. There weren't any relevant commits to REL_10_STABLE that I can
think of. And (with the proviso that I know next to nothing about
Citus) I just cloned https://github.com/citusdata/citus.git and
skimmed through "git diff origin/release-7.4..origin/release-7.5", and
nothing is jumping out at me. Can you still see the problem with
Citus 7.4?
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-08-25 14:46 Sand Stone <sand.m.stone@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sand Stone @ 2018-08-25 14:46 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
>Can you still see the problem with Citus 7.4?
Hi, Thomas. I actually went back to the cluster with Citus7.4 and
PG10.4. And modified the parallel param. So far, I haven't seen any
server crash.
The main difference between crashes observed and no crash, is the set
of Linux TCP time out parameters (to release the ports faster).
Unfortunately, I cannot "undo" the Linux params and run the stress
tests anymore, as this is a multi-million $ cluster and people are
doing more useful things on it. I will keep an eye on any parallel
execution issue.
On Wed, Aug 15, 2018 at 3:43 PM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
>
> On Thu, Aug 16, 2018 at 8:32 AM, Sand Stone <sand.m.stone@gmail.com> wrote:
> > Just as a follow up. I tried the parallel execution again (in a stress
> > test environment). Now the crash seems gone. I will keep an eye on
> > this for the next few weeks.
>
> Thanks for the report. That's great news, but it'd be good to
> understand why it was happening.
>
> > My theory is that the Citus cluster created and shut down a lot of TCP
> > connections between coordinator and workers. If running on untuned
> > Linux machines, the TCP ports might run out.
>
> I'm not sure how that's relevant, unless perhaps it causes executor
> nodes to be invoked in a strange sequence that commit fd7c0fa7 didn't
> fix? I wonder if there could be something different about the control
> flow with custom scans, or something about the way Citus worker nodes
> invoke plan fragments, or some error path that I failed to consider...
> It's a clue that all of your worker nodes reliably crashed at the same
> time on the same/similar queries (presumably distributed query
> fragments for different shards), making it seem more like a
> common-or-garden bug rather than some kind of timing-based heisenbug.
> If you ever manage to reproduce it, an explain plan and a back trace
> would be very useful.
>
> > Of course, I am using "newer" PG10 bits and Citus7.5 this time.
>
> Hmm. There weren't any relevant commits to REL_10_STABLE that I can
> think of. And (with the proviso that I know next to nothing about
> Citus) I just cloned https://github.com/citusdata/citus.git and
> skimmed through "git diff origin/release-7.4..origin/release-7.5", and
> nothing is jumping out at me. Can you still see the problem with
> Citus 7.4?
>
> --
> Thomas Munro
> http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-08-29 04:44 Sand Stone <sand.m.stone@gmail.com>
parent: Sand Stone <sand.m.stone@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sand Stone @ 2018-08-29 04:44 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
I attached a query (and its query plan) that caused the crash:
"dsa_allocate could not find 13 free pages" on one of the worker nodes. I
anonymised the query text a bit. Interestingly, this time only one (same
one) of the nodes is crashing. Since this is a production environment, I
cannot get the stack trace. Once turned off parallel execution for this
node. The whole query finished just fine. So the parallel query plan is
from one of the nodes not crashed, hopefully the same plan would have been
executed on the crashed node. In theory, every worker node has the same
bits, and very similar data.
===
psql (10.4)
\dx
List of installed extensions
Name | Version | Schema | Description
----------------+---------+------------+-----------------------------------
citus | 7.4-3 | pg_catalog | Citus distributed database
hll | 2.10 | public | type for storing hyperloglog data
plpgsql | 1.0 | pg_catalog | PL/pgSQL procedural language
On Sat, Aug 25, 2018 at 7:46 AM Sand Stone <sand.m.stone@gmail.com> wrote:
> >Can you still see the problem with Citus 7.4?
> Hi, Thomas. I actually went back to the cluster with Citus7.4 and
> PG10.4. And modified the parallel param. So far, I haven't seen any
> server crash.
>
> The main difference between crashes observed and no crash, is the set
> of Linux TCP time out parameters (to release the ports faster).
> Unfortunately, I cannot "undo" the Linux params and run the stress
> tests anymore, as this is a multi-million $ cluster and people are
> doing more useful things on it. I will keep an eye on any parallel
> execution issue.
>
>
> On Wed, Aug 15, 2018 at 3:43 PM Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
> >
> > On Thu, Aug 16, 2018 at 8:32 AM, Sand Stone <sand.m.stone@gmail.com>
> wrote:
> > > Just as a follow up. I tried the parallel execution again (in a stress
> > > test environment). Now the crash seems gone. I will keep an eye on
> > > this for the next few weeks.
> >
> > Thanks for the report. That's great news, but it'd be good to
> > understand why it was happening.
> >
> > > My theory is that the Citus cluster created and shut down a lot of TCP
> > > connections between coordinator and workers. If running on untuned
> > > Linux machines, the TCP ports might run out.
> >
> > I'm not sure how that's relevant, unless perhaps it causes executor
> > nodes to be invoked in a strange sequence that commit fd7c0fa7 didn't
> > fix? I wonder if there could be something different about the control
> > flow with custom scans, or something about the way Citus worker nodes
> > invoke plan fragments, or some error path that I failed to consider...
> > It's a clue that all of your worker nodes reliably crashed at the same
> > time on the same/similar queries (presumably distributed query
> > fragments for different shards), making it seem more like a
> > common-or-garden bug rather than some kind of timing-based heisenbug.
> > If you ever manage to reproduce it, an explain plan and a back trace
> > would be very useful.
> >
> > > Of course, I am using "newer" PG10 bits and Citus7.5 this time.
> >
> > Hmm. There weren't any relevant commits to REL_10_STABLE that I can
> > think of. And (with the proviso that I know next to nothing about
> > Citus) I just cloned https://github.com/citusdata/citus.git and
> > skimmed through "git diff origin/release-7.4..origin/release-7.5", and
> > nothing is jumping out at me. Can you still see the problem with
> > Citus 7.4?
> >
> > --
> > Thomas Munro
> > http://www.enterprisedb.com
>
Attachments:
parallelquery-crash-plan.txt (text/plain, 60.0K) download
explain(analyze, verbose) select
atimecol as atimecol, count(1) as count, sum(avg) as sum
from
(
select
partitionid, atimecol as atimecol, avg(sum/count) as avg
from atable
where atimecol >= '7/31/2018' and
atimecol <= '8/28/2018' and
aText = 'Foo' and
(jsoncol ->> 'X') = '-' and id=12345 and acol = 2 and btimecol='7/31/2018' and btimecol<'8/29/2018'
group by partitionid, atimecol
) as subquery
group by atimecol;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=0.00..0.00 rows=0 width=0) (actual time=535.553..535.553 rows=0 loops=1)
Output: remote_scan.atimecol, COALESCE((pg_catalog.sum(remote_scan.count))::bigint, '0'::bigint), sum(remote_scan.sum)
Group Key: remote_scan.atimecol
-> Custom Scan (Citus Real-Time) (cost=0.00..0.00 rows=0 width=0) (actual time=535.551..535.551 rows=0 loops=1)
Output: remote_scan.atimecol, remote_scan.count, remote_scan.sum
Task Count: 40
Tasks Shown: One of 40
-> Task
Node: host=192.168.1.10 port=8432 dbname=measures
-> GroupAggregate (cost=155839.44..155847.88 rows=200 width=24) (actual time=255.514..255.514 rows=0 loops=1)
Output: subquery.atimecol, count(1), sum(subquery.avg)
Group Key: subquery.atimecol
-> Sort (cost=155839.44..155841.05 rows=644 width=16) (actual time=255.513..255.513 rows=0 loops=1)
Output: subquery.atimecol, subquery.avg
Sort Key: subquery.atimecol
Sort Method: quicksort Memory: 25kB
-> Subquery Scan on subquery (cost=155720.69..155809.39 rows=644 width=16) (actual time=255.509..255.509 rows=0 loops=1)
Output: subquery.atimecol, subquery.avg
-> Finalize GroupAggregate (cost=155720.69..155802.95 rows=644 width=24) (actual time=255.508..255.508 rows=0 loops=1)
Output: atable.deviceid, atable.atimecol, avg((atable.sum / (atable.count)::double precision))
Group Key: atable.deviceid, atable.atimecol
-> Gather Merge (cost=155720.69..155790.79 rows=548 width=48) (actual time=255.507..255.507 rows=0 loops=1)
Output: atable.deviceid, atable.atimecol, (PARTIAL avg((atable.sum / (atable.count)::double precision)))
Workers Planned: 2
Workers Launched: 2
-> Partial GroupAggregate (cost=154720.67..154727.52 rows=274 width=48) (actual time=245.145..245.145 rows=0 loops=3)
Output: atable.deviceid, atable.atimecol, PARTIAL avg((atable.sum / (atable.count)::double precision))
Group Key: atable.deviceid, atable.atimecol
Worker 0: actual time=241.308..241.308 rows=0 loops=1
Worker 1: actual time=241.314..241.314 rows=0 loops=1
-> Sort (cost=154720.67..154721.35 rows=274 width=28) (actual time=245.143..245.143 rows=0 loops=3)
Output: atable.deviceid, atable.atimecol, atable.sum, atable.count
Sort Key: atable.deviceid, atable.atimecol
Sort Method: quicksort Memory: 25kB
Worker 0: actual time=241.307..241.307 rows=0 loops=1
Worker 1: actual time=241.312..241.312 rows=0 loops=1
-> Append (cost=107.53..154709.57 rows=274 width=28) (actual time=245.042..245.042 rows=0 loops=3)
Worker 0: actual time=241.159..241.159 rows=0 loops=1
Worker 1: actual time=241.167..241.167 rows=0 loops=1
-> Parallel Bitmap Heap Scan on public.atable_07_31_2018_115891 atable (cost=107.53..5400.41 rows=9 width=28) (actual time=14.439..14.439 rows=0 loops=3)
Output: atable.deviceid, atable.atimecol, atable.sum, atable.count
Recheck Cond: ((atable.id = 12345) AND (atable.acol = 2) AND (atable.atimecol >= '2018-07-31 00:00:00+00'::timestamp with time zone
) AND (atable.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable.aText = 'Foo'::text))
Filter: ((atable.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone) AN
D ((atable.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2901
Heap Blocks: exact=1532
Worker 0: actual time=10.554..10.554 rows=0 loops=1
Worker 1: actual time=10.561..10.561 rows=0 loops=1
-> Bitmap Index Scan on atable_07_31_2018_bar_pidx_115891 (cost=0.00..107.52 rows=4491 width=0) (actual time=1.733..1.733 rows=8704 loops=1)
Index Cond: ((atable.id = 12345) AND (atable.acol = 2) AND (atable.atimecol >= '2018-07-31 00:00:00+00'::timestamp with time
zone) AND (atable.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Index Scan using atable_08_01_2018_bar_pidx_116051 on public.atable_08_01_2018_116051 atable_1 (cost=0.56..5966.67 rows=15 width=28) (actual tim
e=19.664..19.664 rows=0 loops=3)
Output: atable_1.deviceid, atable_1.atimecol, atable_1.sum, atable_1.count
Index Cond: ((atable_1.id = 12345) AND (atable_1.acol = 2) AND (atable_1.atimecol >= '2018-07-31 00:00:00+00'::timestamp with time
zone) AND (atable_1.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Filter: ((atable_1.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_1.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_1.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3310
Worker 0: actual time=20.063..20.063 rows=0 loops=1
Worker 1: actual time=19.530..19.530 rows=0 loops=1
-> Parallel Index Scan using atable_08_02_2018_bar_ux_pidx_116171 on public.atable_08_02_2018_116171 atable_2 (cost=0.42..2.85 rows=1 width=28) (actual ti
me=0.010..0.010 rows=0 loops=3)
Output: atable_2.deviceid, atable_2.atimecol, atable_2.sum, atable_2.count
Index Cond: ((atable_2.id = 12345) AND (atable_2.acol = 2) AND (atable_2.atimecol >= '2018-07-31 00:00:00+00'::timestamp with time
zone) AND (atable_2.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Filter: ((atable_2.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_2.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_2.jsoncol ->> 'X'::text) = '-'::text))
Worker 0: actual time=0.001..0.001 rows=0 loops=1
Worker 1: actual time=0.002..0.002 rows=0 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_03_2018_116371 atable_3 (cost=147.04..7399.29 rows=13 width=28) (actual time=21.362..21.362 rows=0 loops=3)
Output: atable_3.deviceid, atable_3.atimecol, atable_3.sum, atable_3.count
Recheck Cond: ((atable_3.id = 12345) AND (atable_3.acol = 2) AND (atable_3.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_3.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_3.aText = 'Foo'::text))
Filter: ((atable_3.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_3.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_3.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3810
Heap Blocks: exact=1632
Worker 0: actual time=20.975..20.975 rows=0 loops=1
Worker 1: actual time=21.505..21.505 rows=0 loops=1
-> Bitmap Index Scan on atable_08_03_2018_bar_pidx_116371 (cost=0.00..147.03 rows=6165 width=0) (actual time=2.469..2.469 rows=11429 loops=1)
Index Cond: ((atable_3.id = 12345) AND (atable_3.acol = 2) AND (atable_3.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_3.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_04_2018_116531 atable_4 (cost=97.73..4901.29 rows=8 width=28) (actual time=14.063..14.063 rows=0 loops=3)
Output: atable_4.deviceid, atable_4.atimecol, atable_4.sum, atable_4.count
Recheck Cond: ((atable_4.id = 12345) AND (atable_4.acol = 2) AND (atable_4.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_4.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_4.aText = 'Foo'::text))
Filter: ((atable_4.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_4.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_4.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2669
Heap Blocks: exact=1180
Worker 0: actual time=14.063..14.063 rows=0 loops=1
Worker 1: actual time=14.061..14.061 rows=0 loops=1
-> Bitmap Index Scan on atable_08_04_2018_bar_pidx_116531 (cost=0.00..97.72 rows=4078 width=0) (actual time=1.684..1.684 rows=8006 loops=1)
Index Cond: ((atable_4.id = 12345) AND (atable_4.acol = 2) AND (atable_4.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_4.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.684..1.684 rows=8006 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_05_2018_116691 atable_5 (cost=91.55..4597.87 rows=8 width=28) (actual time=12.461..12.461 rows=0 loops=3)
Output: atable_5.deviceid, atable_5.atimecol, atable_5.sum, atable_5.count
Recheck Cond: ((atable_5.id = 12345) AND (atable_5.acol = 2) AND (atable_5.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_5.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_5.aText = 'Foo'::text))
Filter: ((atable_5.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_5.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_5.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2455
Heap Blocks: exact=745
Worker 0: actual time=12.467..12.467 rows=0 loops=1
Worker 1: actual time=12.458..12.458 rows=0 loops=1
-> Bitmap Index Scan on atable_08_05_2018_bar_pidx_116691 (cost=0.00..91.54 rows=3826 width=0) (actual time=1.629..1.629 rows=7365 loops=1)
Index Cond: ((atable_5.id = 12345) AND (atable_5.acol = 2) AND (atable_5.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_5.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.629..1.629 rows=7365 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_06_2018_116851 atable_6 (cost=90.44..4510.33 rows=8 width=28) (actual time=13.344..13.344 rows=0 loops=3)
Output: atable_6.deviceid, atable_6.atimecol, atable_6.sum, atable_6.count
Recheck Cond: ((atable_6.id = 12345) AND (atable_6.acol = 2) AND (atable_6.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_6.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_6.aText = 'Foo'::text))
Filter: ((atable_6.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_6.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_6.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2503
Heap Blocks: exact=1287
Worker 0: actual time=13.341..13.341 rows=0 loops=1
Worker 1: actual time=13.347..13.347 rows=0 loops=1
-> Bitmap Index Scan on atable_08_06_2018_bar_pidx_116851 (cost=0.00..90.43 rows=3752 width=0) (actual time=1.456..1.456 rows=7509 loops=1)
Index Cond: ((atable_6.id = 12345) AND (atable_6.acol = 2) AND (atable_6.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_6.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 1: actual time=1.456..1.456 rows=7509 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_07_2018_117011 atable_7 (cost=104.48..5245.02 rows=9 width=28) (actual time=19.819..19.819 rows=0 loops=3)
Output: atable_7.deviceid, atable_7.atimecol, atable_7.sum, atable_7.count
Recheck Cond: ((atable_7.id = 12345) AND (atable_7.acol = 2) AND (atable_7.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_7.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_7.aText = 'Foo'::text))
Filter: ((atable_7.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_7.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_7.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2950
Heap Blocks: exact=1971
Worker 0: actual time=19.818..19.818 rows=0 loops=1
Worker 1: actual time=19.818..19.818 rows=0 loops=1
-> Bitmap Index Scan on atable_08_07_2018_bar_pidx_117011 (cost=0.00..104.47 rows=4368 width=0) (actual time=2.383..2.383 rows=8851 loops=1)
Index Cond: ((atable_7.id = 12345) AND (atable_7.acol = 2) AND (atable_7.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_7.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_08_2018_117171 atable_8 (cost=98.11..4930.63 rows=9 width=28) (actual time=10.521..10.521 rows=0 loops=3)
Output: atable_8.deviceid, atable_8.atimecol, atable_8.sum, atable_8.count
Recheck Cond: ((atable_8.id = 12345) AND (atable_8.acol = 2) AND (atable_8.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_8.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_8.aText = 'Foo'::text))
Filter: ((atable_8.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_8.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_8.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2725
Heap Blocks: exact=853
Worker 0: actual time=10.520..10.520 rows=0 loops=1
Worker 1: actual time=10.524..10.524 rows=0 loops=1
-> Bitmap Index Scan on atable_08_08_2018_bar_pidx_117171 (cost=0.00..98.10 rows=4103 width=0) (actual time=1.301..1.301 rows=8174 loops=1)
Index Cond: ((atable_8.id = 12345) AND (atable_8.acol = 2) AND (atable_8.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_8.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 1: actual time=1.301..1.301 rows=8174 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_09_2018_117251 atable_9 (cost=100.23..4999.86 rows=9 width=28) (actual time=4.913..4.913 rows=0 loops=3)
Output: atable_9.deviceid, atable_9.atimecol, atable_9.sum, atable_9.count
Recheck Cond: ((atable_9.id = 12345) AND (atable_9.acol = 2) AND (atable_9.atimecol >= '2018-07-31 00:00:00+00'::timestamp with tim
e zone) AND (atable_9.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_9.aText = 'Foo'::text))
Filter: ((atable_9.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_9.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zone
) AND ((atable_9.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2759
Heap Blocks: exact=286
Worker 0: actual time=4.912..4.912 rows=0 loops=1
Worker 1: actual time=4.911..4.911 rows=0 loops=1
-> Bitmap Index Scan on atable_08_09_2018_bar_pidx_117251 (cost=0.00..100.23 rows=4165 width=0) (actual time=1.164..1.164 rows=8277 loops=1)
Index Cond: ((atable_9.id = 12345) AND (atable_9.acol = 2) AND (atable_9.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_9.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.164..1.164 rows=8277 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_10_2018_117451 atable_10 (cost=101.21..5081.85 rows=9 width=28) (actual time=5.534..5.534 rows=0 loops=3)
Output: atable_10.deviceid, atable_10.atimecol, atable_10.sum, atable_10.count
Recheck Cond: ((atable_10.id = 12345) AND (atable_10.acol = 2) AND (atable_10.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_10.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_10.aText = 'Foo'::text))
Filter: ((atable_10.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_10.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_10.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2841
Heap Blocks: exact=307
Worker 0: actual time=5.533..5.533 rows=0 loops=1
Worker 1: actual time=5.538..5.538 rows=0 loops=1
-> Bitmap Index Scan on atable_08_10_2018_bar_pidx_117451 (cost=0.00..101.20 rows=4230 width=0) (actual time=1.121..1.121 rows=8524 loops=1)
Index Cond: ((atable_10.id = 12345) AND (atable_10.acol = 2) AND (atable_10.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_10.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.121..1.121 rows=8524 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_11_2018_117611 atable_11 (cost=107.59..5395.58 rows=9 width=28) (actual time=5.418..5.418 rows=0 loops=3)
Output: atable_11.deviceid, atable_11.atimecol, atable_11.sum, atable_11.count
Recheck Cond: ((atable_11.id = 12345) AND (atable_11.acol = 2) AND (atable_11.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_11.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_11.aText = 'Foo'::text))
Filter: ((atable_11.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_11.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_11.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2953
Heap Blocks: exact=312
Worker 0: actual time=5.423..5.423 rows=0 loops=1
Worker 1: actual time=5.412..5.412 rows=0 loops=1
-> Bitmap Index Scan on atable_08_11_2018_bar_pidx_117611 (cost=0.00..107.58 rows=4495 width=0) (actual time=1.221..1.221 rows=8858 loops=1)
Index Cond: ((atable_11.id = 12345) AND (atable_11.acol = 2) AND (atable_11.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_11.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.221..1.221 rows=8858 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_12_2018_117811 atable_12 (cost=94.89..4769.68 rows=8 width=28) (actual time=5.192..5.192 rows=0 loops=3)
Output: atable_12.deviceid, atable_12.atimecol, atable_12.sum, atable_12.count
Recheck Cond: ((atable_12.id = 12345) AND (atable_12.acol = 2) AND (atable_12.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_12.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_12.aText = 'Foo'::text))
Filter: ((atable_12.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_12.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_12.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2642
Heap Blocks: exact=353
Worker 0: actual time=5.193..5.193 rows=0 loops=1
Worker 1: actual time=5.196..5.196 rows=0 loops=1
-> Bitmap Index Scan on atable_08_12_2018_bar_pidx_117811 (cost=0.00..94.89 rows=3969 width=0) (actual time=0.957..0.957 rows=7927 loops=1)
Index Cond: ((atable_12.id = 12345) AND (atable_12.acol = 2) AND (atable_12.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_12.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 1: actual time=0.957..0.957 rows=7927 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_13_2018_117931 atable_13 (cost=105.37..5308.48 rows=9 width=28) (actual time=4.916..4.916 rows=0 loops=3)
Output: atable_13.deviceid, atable_13.atimecol, atable_13.sum, atable_13.count
Recheck Cond: ((atable_13.id = 12345) AND (atable_13.acol = 2) AND (atable_13.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_13.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_13.aText = 'Foo'::text))
Filter: ((atable_13.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_13.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_13.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2942
Heap Blocks: exact=293
Worker 0: actual time=4.916..4.916 rows=0 loops=1
Worker 1: actual time=4.916..4.916 rows=0 loops=1
-> Bitmap Index Scan on atable_08_13_2018_bar_pidx_117931 (cost=0.00..105.36 rows=4427 width=0) (actual time=1.094..1.094 rows=8827 loops=1)
Index Cond: ((atable_13.id = 12345) AND (atable_13.acol = 2) AND (atable_13.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_13.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_14_2018_118091 atable_14 (cost=124.84..6280.54 rows=11 width=28) (actual time=6.525..6.525 rows=0 loops=3)
Output: atable_14.deviceid, atable_14.atimecol, atable_14.sum, atable_14.count
Recheck Cond: ((atable_14.id = 12345) AND (atable_14.acol = 2) AND (atable_14.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_14.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_14.aText = 'Foo'::text))
Filter: ((atable_14.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_14.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_14.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3573
Heap Blocks: exact=294
Worker 0: actual time=6.522..6.522 rows=0 loops=1
Worker 1: actual time=6.524..6.524 rows=0 loops=1
-> Bitmap Index Scan on atable_08_14_2018_bar_pidx_118091 (cost=0.00..124.83 rows=5245 width=0) (actual time=1.288..1.288 rows=10720 loops=1)
Index Cond: ((atable_14.id = 12345) AND (atable_14.acol = 2) AND (atable_14.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_14.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_15_2018_118251 atable_15 (cost=133.90..6723.57 rows=12 width=28) (actual time=6.582..6.582 rows=0 loops=3)
Output: atable_15.deviceid, atable_15.atimecol, atable_15.sum, atable_15.count
Recheck Cond: ((atable_15.id = 12345) AND (atable_15.acol = 2) AND (atable_15.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_15.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_15.aText = 'Foo'::text))
Filter: ((atable_15.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_15.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_15.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3746
Heap Blocks: exact=397
Worker 0: actual time=6.579..6.579 rows=0 loops=1
Worker 1: actual time=6.585..6.585 rows=0 loops=1
-> Bitmap Index Scan on atable_08_15_2018_bar_pidx_118251 (cost=0.00..133.89 rows=5609 width=0) (actual time=1.477..1.477 rows=11238 loops=1)
Index Cond: ((atable_15.id = 12345) AND (atable_15.acol = 2) AND (atable_15.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_15.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.477..1.477 rows=11238 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_16_2018_118411 atable_16 (cost=101.89..5133.13 rows=9 width=28) (actual time=4.779..4.779 rows=0 loops=3)
Output: atable_16.deviceid, atable_16.atimecol, atable_16.sum, atable_16.count
Recheck Cond: ((atable_16.id = 12345) AND (atable_16.acol = 2) AND (atable_16.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_16.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_16.aText = 'Foo'::text))
Filter: ((atable_16.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_16.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_16.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2814
Heap Blocks: exact=314
Worker 0: actual time=4.783..4.783 rows=0 loops=1
Worker 1: actual time=4.776..4.776 rows=0 loops=1
-> Bitmap Index Scan on atable_08_16_2018_bar_pidx_118411 (cost=0.00..101.88 rows=4275 width=0) (actual time=0.966..0.966 rows=8443 loops=1)
Index Cond: ((atable_16.id = 12345) AND (atable_16.acol = 2) AND (atable_16.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_16.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=0.966..0.966 rows=8443 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_17_2018_118571 atable_17 (cost=113.86..5711.06 rows=10 width=28) (actual time=6.262..6.262 rows=0 loops=3)
Output: atable_17.deviceid, atable_17.atimecol, atable_17.sum, atable_17.count
Recheck Cond: ((atable_17.id = 12345) AND (atable_17.acol = 2) AND (atable_17.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_17.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_17.aText = 'Foo'::text))
Filter: ((atable_17.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_17.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_17.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3220
Heap Blocks: exact=343
Worker 0: actual time=6.263..6.263 rows=0 loops=1
Worker 1: actual time=6.262..6.262 rows=0 loops=1
-> Bitmap Index Scan on atable_08_17_2018_bar_pidx_118571 (cost=0.00..113.85 rows=4753 width=0) (actual time=1.126..1.126 rows=9659 loops=1)
Index Cond: ((atable_17.id = 12345) AND (atable_17.acol = 2) AND (atable_17.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_17.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_18_2018_118731 atable_18 (cost=101.72..5124.76 rows=9 width=28) (actual time=7.255..7.255 rows=0 loops=3)
Output: atable_18.deviceid, atable_18.atimecol, atable_18.sum, atable_18.count
Recheck Cond: ((atable_18.id = 12345) AND (atable_18.acol = 2) AND (atable_18.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_18.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_18.aText = 'Foo'::text))
Filter: ((atable_18.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_18.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_18.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2841
Heap Blocks: exact=319
Worker 0: actual time=7.255..7.255 rows=0 loops=1
Worker 1: actual time=7.254..7.254 rows=0 loops=1
-> Bitmap Index Scan on atable_08_18_2018_bar_pidx_118731 (cost=0.00..101.72 rows=4264 width=0) (actual time=1.235..1.235 rows=8524 loops=1)
Index Cond: ((atable_18.id = 12345) AND (atable_18.acol = 2) AND (atable_18.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_18.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_19_2018_118891 atable_19 (cost=85.13..4277.95 rows=8 width=28) (actual time=5.071..5.071 rows=0 loops=3)
Output: atable_19.deviceid, atable_19.atimecol, atable_19.sum, atable_19.count
Recheck Cond: ((atable_19.id = 12345) AND (atable_19.acol = 2) AND (atable_19.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_19.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_19.aText = 'Foo'::text))
Filter: ((atable_19.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_19.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_19.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2404
Heap Blocks: exact=275
Worker 0: actual time=5.067..5.067 rows=0 loops=1
Worker 1: actual time=5.074..5.074 rows=0 loops=1
-> Bitmap Index Scan on atable_08_19_2018_bar_pidx_118891 (cost=0.00..85.12 rows=3558 width=0) (actual time=1.438..1.438 rows=7211 loops=1)
Index Cond: ((atable_19.id = 12345) AND (atable_19.acol = 2) AND (atable_19.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_19.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_20_2018_119051 atable_20 (cost=100.58..4562.99 rows=8 width=28) (actual time=5.374..5.374 rows=0 loops=3)
Output: atable_20.deviceid, atable_20.atimecol, atable_20.sum, atable_20.count
Recheck Cond: ((atable_20.id = 12345) AND (atable_20.acol = 2) AND (atable_20.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_20.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_20.aText = 'Foo'::text))
Filter: ((atable_20.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_20.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_20.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2534
Heap Blocks: exact=286
Worker 0: actual time=5.375..5.375 rows=0 loops=1
Worker 1: actual time=5.373..5.373 rows=0 loops=1
-> Bitmap Index Scan on atable_08_20_2018_bar_ux_pidx_119051 (cost=0.00..100.57 rows=3788 width=0) (actual time=1.414..1.414 rows=7602 loops=1)
Index Cond: ((atable_20.id = 12345) AND (atable_20.acol = 2) AND (atable_20.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_20.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.414..1.414 rows=7602 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_21_2018_119211 atable_21 (cost=147.83..6724.24 rows=12 width=28) (actual time=7.524..7.524 rows=0 loops=3)
Output: atable_21.deviceid, atable_21.atimecol, atable_21.sum, atable_21.count
Recheck Cond: ((atable_21.id = 12345) AND (atable_21.acol = 2) AND (atable_21.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_21.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_21.aText = 'Foo'::text))
Filter: ((atable_21.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_21.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_21.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3847
Heap Blocks: exact=434
Worker 0: actual time=7.521..7.521 rows=0 loops=1
Worker 1: actual time=7.525..7.525 rows=0 loops=1
-> Bitmap Index Scan on atable_08_21_2018_bar_ux_pidx_119211 (cost=0.00..147.82 rows=5578 width=0) (actual time=1.937..1.937 rows=11540 loops=1)
Index Cond: ((atable_21.id = 12345) AND (atable_21.acol = 2) AND (atable_21.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_21.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_22_2018_119371 atable_22 (cost=142.13..6436.41 rows=11 width=28) (actual time=6.397..6.397 rows=0 loops=3)
Output: atable_22.deviceid, atable_22.atimecol, atable_22.sum, atable_22.count
Recheck Cond: ((atable_22.id = 12345) AND (atable_22.acol = 2) AND (atable_22.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_22.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_22.aText = 'Foo'::text))
Filter: ((atable_22.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_22.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_22.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3397
Heap Blocks: exact=398
Worker 0: actual time=6.400..6.400 rows=0 loops=1
Worker 1: actual time=6.398..6.398 rows=0 loops=1
-> Bitmap Index Scan on atable_08_22_2018_bar_ux_pidx_119371 (cost=0.00..142.12 rows=5358 width=0) (actual time=1.799..1.799 rows=10191 loops=1)
Index Cond: ((atable_22.id = 12345) AND (atable_22.acol = 2) AND (atable_22.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_22.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.799..1.799 rows=10191 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_23_2018_119531 atable_23 (cost=116.21..5237.07 rows=9 width=28) (actual time=4.834..4.834 rows=0 loops=3)
Output: atable_23.deviceid, atable_23.atimecol, atable_23.sum, atable_23.count
Recheck Cond: ((atable_23.id = 12345) AND (atable_23.acol = 2) AND (atable_23.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_23.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_23.aText = 'Foo'::text))
Filter: ((atable_23.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_23.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_23.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2905
Heap Blocks: exact=329
Worker 0: actual time=4.825..4.825 rows=0 loops=1
Worker 1: actual time=4.826..4.826 rows=0 loops=1
-> Bitmap Index Scan on atable_08_23_2018_bar_ux_pidx_119531 (cost=0.00..116.21 rows=4350 width=0) (actual time=1.125..1.125 rows=8716 loops=1)
Index Cond: ((atable_23.id = 12345) AND (atable_23.acol = 2) AND (atable_23.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_23.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_24_2018_119691 atable_24 (cost=117.14..5315.90 rows=9 width=28) (actual time=9.153..9.153 rows=0 loops=3)
Output: atable_24.deviceid, atable_24.atimecol, atable_24.sum, atable_24.count
Recheck Cond: ((atable_24.id = 12345) AND (atable_24.acol = 2) AND (atable_24.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_24.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_24.aText = 'Foo'::text))
Filter: ((atable_24.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_24.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_24.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2987
Heap Blocks: exact=843
Worker 0: actual time=9.164..9.164 rows=0 loops=1
Worker 1: actual time=9.156..9.156 rows=0 loops=1
-> Bitmap Index Scan on atable_08_24_2018_bar_ux_pidx_119691 (cost=0.00..117.13 rows=4412 width=0) (actual time=1.773..1.773 rows=8961 loops=1)
Index Cond: ((atable_24.id = 12345) AND (atable_24.acol = 2) AND (atable_24.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_24.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=1.773..1.773 rows=8961 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_25_2018_119851 atable_25 (cost=139.90..6354.12 rows=11 width=28) (actual time=5.723..5.723 rows=0 loops=3)
Output: atable_25.deviceid, atable_25.atimecol, atable_25.sum, atable_25.count
Recheck Cond: ((atable_25.id = 12345) AND (atable_25.acol = 2) AND (atable_25.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_25.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_25.aText = 'Foo'::text))
Filter: ((atable_25.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_25.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_25.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3346
Heap Blocks: exact=372
Worker 0: actual time=5.723..5.723 rows=0 loops=1
Worker 1: actual time=5.725..5.725 rows=0 loops=1
-> Bitmap Index Scan on atable_08_25_2018_bar_ux_pidx_119851 (cost=0.00..139.89 rows=5289 width=0) (actual time=1.282..1.282 rows=10037 loops=1)
Index Cond: ((atable_25.id = 12345) AND (atable_25.acol = 2) AND (atable_25.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_25.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_26_2018_120011 atable_26 (cost=108.27..4887.59 rows=8 width=28) (actual time=4.662..4.662 rows=0 loops=3)
Output: atable_26.deviceid, atable_26.atimecol, atable_26.sum, atable_26.count
Recheck Cond: ((atable_26.id = 12345) AND (atable_26.acol = 2) AND (atable_26.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_26.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_26.aText = 'Foo'::text))
Filter: ((atable_26.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_26.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_26.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 2645
Heap Blocks: exact=301
Worker 0: actual time=4.664..4.664 rows=0 loops=1
Worker 1: actual time=4.654..4.654 rows=0 loops=1
-> Bitmap Index Scan on atable_08_26_2018_bar_ux_pidx_120011 (cost=0.00..108.27 rows=4061 width=0) (actual time=1.043..1.043 rows=7934 loops=1)
Index Cond: ((atable_26.id = 12345) AND (atable_26.acol = 2) AND (atable_26.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_26.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
-> Parallel Bitmap Heap Scan on public.atable_08_27_2018_120171 atable_27 (cost=147.65..5934.25 rows=10 width=28) (actual time=5.573..5.573 rows=0 loops=3)
Output: atable_27.deviceid, atable_27.atimecol, atable_27.sum, atable_27.count
Recheck Cond: ((atable_27.id = 12345) AND (atable_27.acol = 2) AND (atable_27.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_27.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_27.aText = 'Foo'::text))
Filter: ((atable_27.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_27.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_27.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 3070
Heap Blocks: exact=336
Worker 0: actual time=5.564..5.564 rows=0 loops=1
Worker 1: actual time=5.584..5.584 rows=0 loops=1
-> Bitmap Index Scan on atable_08_27_2018_bar_ux_pidx_120171 (cost=0.00..147.65 rows=4926 width=0) (actual time=1.656..1.656 rows=9211 loops=1)
Index Cond: ((atable_27.id = 12345) AND (atable_27.acol = 2) AND (atable_27.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_27.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 1: actual time=1.656..1.656 rows=9211 loops=1
-> Parallel Bitmap Heap Scan on public.atable_08_28_2018_120331 atable_28 (cost=187.61..7496.18 rows=13 width=28) (actual time=7.649..7.649 rows=0 loops=3)
Output: atable_28.deviceid, atable_28.atimecol, atable_28.sum, atable_28.count
Recheck Cond: ((atable_28.id = 12345) AND (atable_28.acol = 2) AND (atable_28.atimecol >= '2018-07-31 00:00:00+00'::timestamp with
time zone) AND (atable_28.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone) AND (atable_28.aText = 'Foo'::text))
Filter: ((atable_28.procdatetime >= '2018-07-31 00:00:00+00'::timestamp with time zone) AND (atable_28.procdatetime < '2018-08-29 00:00:00+00'::timestamp with time zo
ne) AND ((atable_28.jsoncol ->> 'X'::text) = '-'::text))
Rows Removed by Filter: 4018
Heap Blocks: exact=530
Worker 0: actual time=7.651..7.651 rows=0 loops=1
Worker 1: actual time=7.650..7.650 rows=0 loops=1
-> Bitmap Index Scan on atable_08_28_2018_bar_ux_pidx_120331 (cost=0.00..187.61 rows=6230 width=0) (actual time=2.161..2.161 rows=12055 loops=1)
Index Cond: ((atable_28.id = 12345) AND (atable_28.acol = 2) AND (atable_28.atimecol >= '2018-07-31 00:00:00+00'::timestamp w
ith time zone) AND (atable_28.atimecol <= '2018-08-28 00:00:00+00'::timestamp with time zone))
Worker 0: actual time=2.161..2.161 rows=12055 loops=1
Planning time: 83.668 ms
Execution time: 301.567 ms
Planning time: 6.734 ms
Execution time: 535.688 ms
(341 rows)
Time: 944.180 ms
* Re: dsa_allocate() faliure
@ 2018-10-05 02:16 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Sand Stone <sand.m.stone@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-10-05 02:16 UTC (permalink / raw)
To: Sand Stone <sand.m.stone@gmail.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org, Robert Haas <robertmhaas@gmail.com>
On Wed, Aug 29, 2018 at 5:48 PM Sand Stone <sand.m.stone@gmail.com> wrote:
> I attached a query (and its query plan) that caused the crash: "dsa_allocate could not find 13 free pages" on one of the worker nodes. I anonymised the query text a bit. Interestingly, this time only one (same one) of the nodes is crashing. Since this is a production environment, I cannot get the stack trace. Once turned off parallel execution for this node. The whole query finished just fine. So the parallel query plan is from one of the nodes not crashed, hopefully the same plan would have been executed on the crashed node. In theory, every worker node has the same bits, and very similar data.
I wonder if this was a different symptom of the problem fixed here:
https://www.postgresql.org/message-id/flat/194c0706-c65b-7d81-ab32-2c248c3e2344%402ndquadrant.com
Can you still reproduce it on current master, REL_11_STABLE or REL_10_STABLE?
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-13 13:08 Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-13 13:08 UTC (permalink / raw)
To: pgsql-performance
Hi, I'm also experiencing the problem: dsa_allocate could not find 7 free
pages CONTEXT: parallel worker
I'm running: PostgreSQL 10.5 (Ubuntu 10.5-1.pgdg16.04+1) on
x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.10) 5.4.0
20160609, 64-bit
query plan: (select statement over parent table to many partitions):
select ...
from fa
where c_id in (<ID_LIST>) and
datetime >= '2018/01/01'
and ((dims ? 'p' and dims ? 'mcp')
or (datasource in (FA', 'GA')))
and not datasource = 'm'
GROUP BY datasource, dims ->'ct', dims ->'mcp', dims -> 'p', dims -> 'sp':
Finalize GroupAggregate (cost=31514757.77..31519357.77 rows=40000 width=223)
Group Key: fa.datasource, ((fa.dims -> 'ct'::text)), ((fa.dims ->
'mcp'::text)), ((fa.dims -> 'p'::text)), ((fa.dims -> 'sp'::text))
-> Sort (cost=31514757.77..31515057.77 rows=120000 width=223)
Sort Key: fa.datasource, ((fa.dims -> 'ct'::text)), ((fa.dims
-> 'mcp'::text)), ((fa.dims -> 'p'::text)), ((fa.dims -> 'sp'::text))
-> Gather (cost=31491634.17..31504634.17 rows=120000 width=223)
Workers Planned: 3
-> Partial HashAggregate
(cost=31490634.17..31491634.17 rows=40000 width=223)
Group Key: fa.datasource, (fa.dims ->
'ct'::text), (fa.dims -> 'mcp'::text), (fa.dims -> 'p'::text),
(fa.dims -> 'sp'::text)
-> Result (cost=0.00..31364713.39 rows=5596479 width=175)
-> Append (cost=0.00..31252783.81
rows=5596479 width=659)
-> Parallel Seq Scan on fa
(cost=0.00..0.00 rows=1 width=580)
Filter: ((datetime >=
'2018-01-01 00:00:00+01'::timestamp with time zone) AND
((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ?
'mcp'::text)) OR ((datasource)::text =
ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('{<ID_LIST>}'::bigint[])))
-> Parallel Bitmap Heap Scan on
fa_10 (cost=1226.36..53641.49 rows=1 width=1290)
Recheck Cond: (datetime >=
'2018-01-01 00:00:00+01'::timestamp with time zone)
Filter: (((datasource)::text <>
'M'::text) AND (((dims ? 'p'::text) AND (dims ? 'mcp'::text)) OR
((datasource)::text = ANY ('<ID_LIST>'::bigint[])))
-> Bitmap Index Scan on
fa_10_rangestart (cost=0.00..1226.36 rows=32259 width=0)
Index Cond: (datetime >=
'2018-01-01 00:00:00+01'::timestamp with time zone)
-> Parallel Seq Scan on fa_105
(cost=0.00..11.99 rows=1 width=580)
Filter: ((datetime >=
'2018-01-01 00:00:00+01'::timestamp with time zone) AND
((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ?
'mcp'::text)) OR ((datasource)::text =
ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('<ID_LIST>'::bigint[])))
-> Parallel Seq Scan on fa_106
(cost=0.00..11.99 rows=1 width=580)
Filter: ((datetime >=
'2018-01-01 00:00:00+01'::timestamp with time zone) AND
((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ?
'mcp'::text)) OR ((datasource)::text =
ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('<ID_LIST>..........
--
regards,
Jakub Glapa
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-21 14:26 Jakub Glapa <jakub.glapa@gmail.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-21 14:26 UTC (permalink / raw)
To: pgsql-performance
Looks like my email didn't match the right thread:
https://www.postgresql.org/message-id/flat/CAMAYy4%2Bw3NTBM5JLWFi8twhWK4%3Dk_5L4nV5%2BbYDSPu8r4b97Zg...
Any chance to get some feedback on this?
--
regards,
Jakub Glapa
On Tue, Nov 13, 2018 at 2:08 PM Jakub Glapa <jakub.glapa@gmail.com> wrote:
> Hi, I'm also experiencing the problem: dsa_allocate could not find 7 free
> pages CONTEXT: parallel worker
>
> I'm running: PostgreSQL 10.5 (Ubuntu 10.5-1.pgdg16.04+1) on
> x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.10) 5.4.0
> 20160609, 64-bit
>
> query plan: (select statement over parent table to many partitions):
> select ...
> from fa
> where c_id in (<ID_LIST>) and
> datetime >= '2018/01/01'
> and ((dims ? 'p' and dims ? 'mcp')
> or (datasource in (FA', 'GA')))
> and not datasource = 'm'
> GROUP BY datasource, dims ->'ct', dims ->'mcp', dims -> 'p', dims -> 'sp':
>
> Finalize GroupAggregate (cost=31514757.77..31519357.77 rows=40000 width=223)
> Group Key: fa.datasource, ((fa.dims -> 'ct'::text)), ((fa.dims -> 'mcp'::text)), ((fa.dims -> 'p'::text)), ((fa.dims -> 'sp'::text))
> -> Sort (cost=31514757.77..31515057.77 rows=120000 width=223)
> Sort Key: fa.datasource, ((fa.dims -> 'ct'::text)), ((fa.dims -> 'mcp'::text)), ((fa.dims -> 'p'::text)), ((fa.dims -> 'sp'::text))
> -> Gather (cost=31491634.17..31504634.17 rows=120000 width=223)
> Workers Planned: 3
> -> Partial HashAggregate (cost=31490634.17..31491634.17 rows=40000 width=223)
> Group Key: fa.datasource, (fa.dims -> 'ct'::text), (fa.dims -> 'mcp'::text), (fa.dims -> 'p'::text), (fa.dims -> 'sp'::text)
> -> Result (cost=0.00..31364713.39 rows=5596479 width=175)
> -> Append (cost=0.00..31252783.81 rows=5596479 width=659)
> -> Parallel Seq Scan on fa (cost=0.00..0.00 rows=1 width=580)
> Filter: ((datetime >= '2018-01-01 00:00:00+01'::timestamp with time zone) AND ((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ? 'mcp'::text)) OR ((datasource)::text =
> ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('{<ID_LIST>}'::bigint[])))
> -> Parallel Bitmap Heap Scan on fa_10 (cost=1226.36..53641.49 rows=1 width=1290)
> Recheck Cond: (datetime >= '2018-01-01 00:00:00+01'::timestamp with time zone)
> Filter: (((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ? 'mcp'::text)) OR ((datasource)::text = ANY ('<ID_LIST>'::bigint[])))
> -> Bitmap Index Scan on fa_10_rangestart (cost=0.00..1226.36 rows=32259 width=0)
> Index Cond: (datetime >= '2018-01-01 00:00:00+01'::timestamp with time zone)
> -> Parallel Seq Scan on fa_105 (cost=0.00..11.99 rows=1 width=580)
> Filter: ((datetime >= '2018-01-01 00:00:00+01'::timestamp with time zone) AND ((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ? 'mcp'::text)) OR ((datasource)::text =
> ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('<ID_LIST>'::bigint[])))
> -> Parallel Seq Scan on fa_106 (cost=0.00..11.99 rows=1 width=580)
> Filter: ((datetime >= '2018-01-01 00:00:00+01'::timestamp with time zone) AND ((datasource)::text <> 'M'::text) AND (((dims ? 'p'::text) AND (dims ? 'mcp'::text)) OR ((datasource)::text =
> ANY ('{"FA","GA"}'::text[]))) AND (c_id = ANY ('<ID_LIST>..........
>
>
>
> --
> regards,
> Jakub Glapa
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-22 16:09 Justin Pryzby <pryzby@telsasoft.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2018-11-22 16:09 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: pgsql-performance
On Wed, Nov 21, 2018 at 03:26:42PM +0100, Jakub Glapa wrote:
> Looks like my email didn't match the right thread:
> https://www.postgresql.org/message-id/flat/CAMAYy4%2Bw3NTBM5JLWFi8twhWK4%3Dk_5L4nV5%2BbYDSPu8r4b97Zg...
> Any chance to get some feedback on this?
In the related thread, it looks like Thomas backpatched a fix to v10, and so I
guess this should be resolved in 10.6, which was released couple weeks ago.
https://www.postgresql.org/message-id/CAEepm%3D0QxoUSkFqYbvmxi2eNvvU6BkqH6fTOu4oOzc1MRAT4Dw%40mail.g...
Could you upgrade and check ?
38763d67784c6563d08dbea5c9f913fa174779b8 in master
|commit ba20d392584cdecc2808fe936448d127f43f2c07
|Author: Thomas Munro <tmunro@postgresql.org>
|Date: Thu Sep 20 15:52:39 2018 +1200
|
| Fix segment_bins corruption in dsa.c.
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-23 14:31 Jakub Glapa <jakub.glapa@gmail.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-23 14:31 UTC (permalink / raw)
To: pryzby@telsasoft.com; +Cc: pgsql-performance
Hi Justin, I've upgrade to 10.6 but the error still shows up:
psql db@host as user => select version();
version
─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
PostgreSQL 10.6 (Ubuntu 10.6-1.pgdg16.04+1) on x86_64-pc-linux-gnu,
compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.10) 5.4.0 20160609, 64-bit
(1 row)
Time: 110.512 ms
psql db@host as user => select <COLUMNS> from fa where client_id in
(<IDS>) and datetime >= '2018/01/01' and ((dims ? 'p' and dimensions ?
'mcp') or (datasource in ('FA', 'GA'))) and not datasource = 'M' GROUP BY
datasource, dims ->'ct', dimensions ->'mct', dims -> 'p', dims -> 'sp';
ERROR: XX000: dsa_allocate could not find 7 free pages
CONTEXT: parallel worker
LOCATION: dsa_allocate_extended, dsa.c:729
Time: 131400.831 ms (02:11.401)
the above is execute with max_parallel_workers=8
If I set it to max_parallel_workers=0 I also get and my connection is being
closed (but the server is alive):
psql db@host as user => set max_parallel_workers=0;
SET
Time: 89.542 ms
psql db@host as user => SELECT <QUERY>;
FATAL: XX000: dsa_allocate could not find 7 free pages
LOCATION: dsa_allocate_extended, dsa.c:729
SSL connection has been closed unexpectedly
The connection to the server was lost. Attempting reset: Succeeded.
Time: 200390.466 ms (03:20.390)
--
regards,
Jakub Glapa
On Thu, Nov 22, 2018 at 5:10 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> On Wed, Nov 21, 2018 at 03:26:42PM +0100, Jakub Glapa wrote:
> > Looks like my email didn't match the right thread:
> >
> https://www.postgresql.org/message-id/flat/CAMAYy4%2Bw3NTBM5JLWFi8twhWK4%3Dk_5L4nV5%2BbYDSPu8r4b97Zg...
> > Any chance to get some feedback on this?
>
> In the related thread, it looks like Thomas backpatched a fix to v10, and
> so I
> guess this should be resolved in 10.6, which was released couple weeks ago.
>
> https://www.postgresql.org/message-id/CAEepm%3D0QxoUSkFqYbvmxi2eNvvU6BkqH6fTOu4oOzc1MRAT4Dw%40mail.g...
>
> Could you upgrade and check ?
>
> 38763d67784c6563d08dbea5c9f913fa174779b8 in master
>
> |commit ba20d392584cdecc2808fe936448d127f43f2c07
> |Author: Thomas Munro <tmunro@postgresql.org>
> |Date: Thu Sep 20 15:52:39 2018 +1200
> |
> | Fix segment_bins corruption in dsa.c.
>
> Justin
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-23 16:10 Justin Pryzby <pryzby@telsasoft.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2018-11-23 16:10 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: pgsql-performance
On Fri, Nov 23, 2018 at 03:31:41PM +0100, Jakub Glapa wrote:
> Hi Justin, I've upgrade to 10.6 but the error still shows up:
>
> If I set it to max_parallel_workers=0 I also get and my connection is being
> closed (but the server is alive):
>
> psql db@host as user => set max_parallel_workers=0;
Can you show the plan (explain without analyze) for the nonparallel case?
Also, it looks like the server crashed in that case (even if it restarted
itself quickly). Can you confirm ?
For example: dmesg |tail might show "postmaster[8582]: segfault [...]" or
similar. And other clients would've been disconnected. (For example, you'd
get an error in another, previously-connected session the next time you run:
SELECT 1).
In any case, could you try to find a minimal way to reproduce the problem ? I
mean, is the dataset and query small and something you can publish, or can you
reproduce with data generated from (for example) generate_series() ?
Thanks,
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-26 15:26 Jakub Glapa <jakub.glapa@gmail.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-26 15:26 UTC (permalink / raw)
To: pryzby@telsasoft.com; +Cc: pgsql-performance
So, the issue occurs only on production db an right now I cannot reproduce
it.
I had a look at dmesg and indeed I see something like:
--
regards,
pozdrawiam,
Jakub Glapa
On Fri, Nov 23, 2018 at 5:10 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> On Fri, Nov 23, 2018 at 03:31:41PM +0100, Jakub Glapa wrote:
> > Hi Justin, I've upgrade to 10.6 but the error still shows up:
> >
> > If I set it to max_parallel_workers=0 I also get and my connection is
> being
> > closed (but the server is alive):
> >
> > psql db@host as user => set max_parallel_workers=0;
>
> Can you show the plan (explain without analyze) for the nonparallel case?
>
> Also, it looks like the server crashed in that case (even if it restarted
> itself quickly). Can you confirm ?
>
> For example: dmesg |tail might show "postmaster[8582]: segfault [...]" or
> similar. And other clients would've been disconnected. (For example,
> you'd
> get an error in another, previously-connected session the next time you
> run:
> SELECT 1).
>
> In any case, could you try to find a minimal way to reproduce the problem
> ? I
> mean, is the dataset and query small and something you can publish, or can
> you
> reproduce with data generated from (for example) generate_series() ?
>
> Thanks,
> Justin
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-26 15:38 Jakub Glapa <jakub.glapa@gmail.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-26 15:38 UTC (permalink / raw)
To: pryzby@telsasoft.com; +Cc: pgsql-performance
sorry, the message was sent out to early.
So, the issue occurs only on production db an right now I cannot reproduce
it.
I had a look at dmesg and indeed I see something like:
postgres[30667]: segfault at 0 ip 0000557834264b16 sp 00007ffc2ce1e030
error 4 in postgres[557833db7000+6d5000]
and AFAIR other sessions I had opened at that time were indeed disconnected.
When it comes to the execution plan for max_parallel_workers=0.
There is no real difference.
I guess *max_parallel_workers *has no effect and
*max_parallel_workers_per_gather
*should have been used.
Why it caused a server crash is unknown right now.
I cannot really give a reproducible recipe.
My case is that I have a parent table with ~300 partitions.
And I initiate a select on ~100 of them with select [...] from fa where
client_id(<IDS>) and [filters].
I know this is not effective. Every partition has several indexes and this
query acquires a lot of locks... even for relations not used in the query.
PG11 should have better partition pruning mechanism but I'm not there yet
to upgrade.
Some of the partitions have millions of rows.
I'll keep observing maybe I'l find a pattern when this occurs.
--
regards,
pozdrawiam,
Jakub Glapa
On Mon, Nov 26, 2018 at 4:26 PM Jakub Glapa <jakub.glapa@gmail.com> wrote:
> So, the issue occurs only on production db an right now I cannot reproduce
> it.
> I had a look at dmesg and indeed I see something like:
>
>
> --
> regards,
> Jakub Glapa
>
>
> On Fri, Nov 23, 2018 at 5:10 PM Justin Pryzby <pryzby@telsasoft.com>
> wrote:
>
>> On Fri, Nov 23, 2018 at 03:31:41PM +0100, Jakub Glapa wrote:
>> > Hi Justin, I've upgrade to 10.6 but the error still shows up:
>> >
>> > If I set it to max_parallel_workers=0 I also get and my connection is
>> being
>> > closed (but the server is alive):
>> >
>> > psql db@host as user => set max_parallel_workers=0;
>>
>> Can you show the plan (explain without analyze) for the nonparallel case?
>>
>> Also, it looks like the server crashed in that case (even if it restarted
>> itself quickly). Can you confirm ?
>>
>> For example: dmesg |tail might show "postmaster[8582]: segfault [...]" or
>> similar. And other clients would've been disconnected. (For example,
>> you'd
>> get an error in another, previously-connected session the next time you
>> run:
>> SELECT 1).
>>
>> In any case, could you try to find a minimal way to reproduce the problem
>> ? I
>> mean, is the dataset and query small and something you can publish, or
>> can you
>> reproduce with data generated from (for example) generate_series() ?
>>
>> Thanks,
>> Justin
>>
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-26 15:52 Justin Pryzby <pryzby@telsasoft.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 2 replies; 60+ messages in thread
From: Justin Pryzby @ 2018-11-26 15:52 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: pgsql-performance@postgresql.org, Thomas Munro <thomas.munro@enterprisedb.com>
Hi, thanks for following through.
On Mon, Nov 26, 2018 at 04:38:35PM +0100, Jakub Glapa wrote:
> I had a look at dmesg and indeed I see something like:
>
> postgres[30667]: segfault at 0 ip 0000557834264b16 sp 00007ffc2ce1e030
> error 4 in postgres[557833db7000+6d5000]
That's useful, I think "at 0" means a null pointer dereferenced.
Can you check /var/log/messages (or ./syslog or similar) and verify the
timestamp matches the time of the last crash (and not an unrelated crash) ?
The logs might also indicate if the process dumped a core file anywhere.
I don't know what distribution/OS you're using, but it might be good to install
abrt (RHEL) or apport (ubuntu) or other mechanism to save coredumps, or to
manually configure /proc/sys/kernel/core_pattern.
On centos, I usually set:
/etc/abrt/abrt-action-save-package-data.conf
OpenGPGCheck = no
Also, it might be good to install debug symbols, in case you do find a core
dump now or get one later.
On centos: yum install postgresql10-debuginfo or debuginfo-install postgresql10-server
Make sure this exactly matches the debug symbols exactly match the server version.
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-26 16:00 Jakub Glapa <jakub.glapa@gmail.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
1 sibling, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-26 16:00 UTC (permalink / raw)
To: pryzby@telsasoft.com; +Cc: pgsql-performance@postgresql.org, Thomas Munro <thomas.munro@enterprisedb.com>
Justin thanks for the information!
I'm running Ubuntu 16.04.
I'll try to prepare for the next crash.
Couldn't find anything this time.
--
regards,
Jakub Glapa
On Mon, Nov 26, 2018 at 4:52 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> Hi, thanks for following through.
>
> On Mon, Nov 26, 2018 at 04:38:35PM +0100, Jakub Glapa wrote:
> > I had a look at dmesg and indeed I see something like:
> >
> > postgres[30667]: segfault at 0 ip 0000557834264b16 sp 00007ffc2ce1e030
> > error 4 in postgres[557833db7000+6d5000]
>
> That's useful, I think "at 0" means a null pointer dereferenced.
>
> Can you check /var/log/messages (or ./syslog or similar) and verify the
> timestamp matches the time of the last crash (and not an unrelated crash) ?
>
> The logs might also indicate if the process dumped a core file anywhere.
>
> I don't know what distribution/OS you're using, but it might be good to
> install
> abrt (RHEL) or apport (ubuntu) or other mechanism to save coredumps, or to
> manually configure /proc/sys/kernel/core_pattern.
>
> On centos, I usually set:
> /etc/abrt/abrt-action-save-package-data.conf
> OpenGPGCheck = no
>
> Also, it might be good to install debug symbols, in case you do find a core
> dump now or get one later.
>
> On centos: yum install postgresql10-debuginfo or debuginfo-install
> postgresql10-server
> Make sure this exactly matches the debug symbols exactly match the server
> version.
>
> Justin
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-26 18:45 Alvaro Herrera <alvherre@2ndquadrant.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Alvaro Herrera @ 2018-11-26 18:45 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: pryzby@telsasoft.com, pgsql-performance@postgresql.org, Thomas Munro <thomas.munro@enterprisedb.com>
On 2018-Nov-26, Jakub Glapa wrote:
> Justin thanks for the information!
> I'm running Ubuntu 16.04.
> I'll try to prepare for the next crash.
> Couldn't find anything this time.
As I recall, the appport stuff in Ubuntu is terrible ... I've seen it
take 40 minutes to write the crash dump to disk, during which the
database was "down". I don't know why it is so slow (it's a rather
silly python script that apparently processes the core dump one byte at
a time, and you can imagine that with a few gigabytes of shared memory
that takes a while). Anyway my recommendation was to *remove* that
stuff from the server and make sure the core file is saved by normal
means.
--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-27 03:00 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Alvaro Herrera <alvherre@2ndquadrant.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-11-27 03:00 UTC (permalink / raw)
To: Alvaro Herrera <alvherre@2ndquadrant.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Pg Hackers <pgsql-hackers@postgresql.org>
On Tue, Nov 27, 2018 at 7:45 AM Alvaro Herrera <alvherre@2ndquadrant.com> wrote:
> On 2018-Nov-26, Jakub Glapa wrote:
> > Justin thanks for the information!
> > I'm running Ubuntu 16.04.
> > I'll try to prepare for the next crash.
> > Couldn't find anything this time.
>
> As I recall, the appport stuff in Ubuntu is terrible ... I've seen it
> take 40 minutes to write the crash dump to disk, during which the
> database was "down". I don't know why it is so slow (it's a rather
> silly python script that apparently processes the core dump one byte at
> a time, and you can imagine that with a few gigabytes of shared memory
> that takes a while). Anyway my recommendation was to *remove* that
> stuff from the server and make sure the core file is saved by normal
> means.
Thanks for CC-ing me. I didn't see this thread earlier because I'm
not subscribed to -performance. Let's move it over to -hackers since
it looks like it's going to be a debugging exercise. So, reading
through the thread[1], I think there might be two independent problems
here:
1. Jakub has a many-partition Parallel Bitmap Heap Scan query that
segfaults when run with max_parallel_workers = 0. That sounds
suspiciously like an instance of a class of bug we've run into before.
We planned a parallel query, but were unable to launch one due to lack
of DSM slots or process slots, so we run the parallel plan in a kind
of degraded non-parallel mode that needs to cope with various pointers
into shared memory being NULL. A back trace from a core file should
hopefully make it very obvious what's going on.
2. The same query when run in real parallel query mode occasionally
reaches an error "dsa_allocate could not find 7 free pages", which
should not happen. This is on 10.6, so it has the commit "Fix
segment_bins corruption in dsa.c.".
Hmm. I will see if I can come up with a many-partition torture test
reproducer for this.
[1] https://www.postgresql.org/message-id/flat/CAJk1zg10iCNsxFvQ4pgKe1B0rdjNG9iELA7AzLXjXnQm5T%3DKzQ%40m...
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-27 08:02 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2018-11-27 08:02 UTC (permalink / raw)
To: Alvaro Herrera <alvherre@2ndquadrant.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Pg Hackers <pgsql-hackers@postgresql.org>
On Tue, Nov 27, 2018 at 4:00 PM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> Hmm. I will see if I can come up with a many-partition torture test
> reproducer for this.
No luck. I suppose one theory that could link both failure modes
would a buffer overrun, where in the non-shared case it trashes a
pointer that is later dereferenced, and in the shared case it writes
past the end of allocated 4KB pages and corrupts the intrusive btree
that lives in spare pages to track available space.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-30 19:20 Jakub Glapa <jakub.glapa@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2018-11-30 19:20 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: alvherre@2ndquadrant.com; pryzby@telsasoft.com; pgsql-hackers@postgresql.org
Hi, just a small update.
I've configured the OS for taking crash dumps on Ubuntu 16.04 with the
following (maybe somebody will find it helpful):
I've added LimitCORE=infinity to /lib/systemd/system/postgresql@.service
under [Service] section
I've reloaded the service config with sudo systemctl daemon-reload
Changed the core pattern to: sudo echo
/var/lib/postgresql/core.%p.sig%s.%ts | tee -a /proc/sys/kernel/core_pattern
I had tested it with kill -ABRT pidofbackend and it behaved correctly. A
crash dump was written.
In the last days I've been monitoring no segfault occurred but the
das_allocation did.
I'm starting to doubt if the segfault I've found in dmesg was actually
related.
I've grepped the postgres log for dsa_allocated:
Why do the messages occur sometimes as FATAL and sometimes as ERROR?
2018-11-29 07:59:06 CET::@:[20584]: FATAL: dsa_allocate could not find 7
free pages
2018-11-29 07:59:06 CET:127.0.0.1(40846):user@db:[19507]: ERROR:
dsa_allocate could not find 7 free pages
2018-11-30 09:04:13 CET::@:[27341]: FATAL: dsa_allocate could not find 13
free pages
2018-11-30 09:04:13 CET:127.0.0.1(41782):user@db:[25417]: ERROR:
dsa_allocate could not find 13 free pages
2018-11-30 09:28:38 CET::@:[30215]: FATAL: dsa_allocate could not find 4
free pages
2018-11-30 09:28:38 CET:127.0.0.1(45980):user@db:[29924]: ERROR:
dsa_allocate could not find 4 free pages
2018-11-30 16:37:16 CET::@:[14385]: FATAL: dsa_allocate could not find 7
free pages
2018-11-30 16:37:16 CET::@:[14375]: FATAL: dsa_allocate could not find 7
free pages
2018-11-30 16:37:16 CET:212.186.105.45(55004):user@db:[14386]: FATAL:
dsa_allocate could not find 7 free pages
2018-11-30 16:37:16 CET:212.186.105.45(54964):user@db:[14379]: ERROR:
dsa_allocate could not find 7 free pages
2018-11-30 16:37:16 CET:212.186.105.45(54916):user@db:[14370]: ERROR:
dsa_allocate could not find 7 free pages
2018-11-30 16:45:11 CET:212.186.105.45(55356):user@db:[14555]: FATAL:
dsa_allocate could not find 7 free pages
2018-11-30 16:49:13 CET::@:[15359]: FATAL: dsa_allocate could not find 7
free pages
2018-11-30 16:49:13 CET::@:[15363]: FATAL: dsa_allocate could not find 7
free pages
2018-11-30 16:49:13 CET:212.186.105.45(54964):user@db:[14379]: FATAL:
dsa_allocate could not find 7 free pages
2018-11-30 16:49:13 CET:212.186.105.45(54916):user@db:[14370]: ERROR:
dsa_allocate could not find 7 free pages
2018-11-30 16:49:13 CET:212.186.105.45(55842):user@db:[14815]: ERROR:
dsa_allocate could not find 7 free pages
2018-11-30 16:56:11 CET:212.186.105.45(57076):user@db:[15638]: FATAL:
dsa_allocate could not find 7 free pages
There's quite a bit errors from today but I was launching the problematic
query in parallel from 2-3 sessions.
Sometimes it was breaking sometimes not.
Couldn't find any pattern.
The workload on this db is not really constant, rather bursting.
--
regards,
Jakub Glapa
On Tue, Nov 27, 2018 at 9:03 AM Thomas Munro <thomas.munro@enterprisedb.com>
wrote:
> On Tue, Nov 27, 2018 at 4:00 PM Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
> > Hmm. I will see if I can come up with a many-partition torture test
> > reproducer for this.
>
> No luck. I suppose one theory that could link both failure modes
> would a buffer overrun, where in the non-shared case it trashes a
> pointer that is later dereferenced, and in the shared case it writes
> past the end of allocated 4KB pages and corrupts the intrusive btree
> that lives in spare pages to track available space.
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2018-11-30 20:46 Justin Pryzby <pryzby@telsasoft.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2018-11-30 20:46 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; alvherre@2ndquadrant.com; pgsql-hackers@postgresql.org
On Fri, Nov 30, 2018 at 08:20:49PM +0100, Jakub Glapa wrote:
> In the last days I've been monitoring no segfault occurred but the
> das_allocation did.
> I'm starting to doubt if the segfault I've found in dmesg was actually
> related.
The dmesg looks like a real crash, not just OOM. You can hopefully find the
timestamp of the segfaults in /var/log/syslog, and compare with postgres logs
if they go back far enough. All the postgres processes except the parent
would've been restarted at that time.
> I've grepped the postgres log for dsa_allocated:
> Why do the messages occur sometimes as FATAL and sometimes as ERROR?
I believe it may depend if it happens in a parallel worker or the leader.
You may get more log detail if you enable CSV logging (although unfortunately
as I recall it doesn't indicate it's a parallel worker).
You could force it to dump core if you recompile postgres with an assert() (see
patch below).
You could build an .deb by running dpkg-buildpackage -rfakeroot or similar (i
haven't done this in awhile), or you could compile, install, and launch
debugging binaries from your homedir (or similar)
You'd want to compile the same version (git checkout REL_10_6) and with the
proper configure flags..perhaps starting with:
./configure --with-libxml --with-libxslt --enable-debug --prefix=$HOME/src/postgresql.bin --enable-cassert && time make && make install
Be careful if you have extensions installed that they still work.
Justin
inline patch 1: src/backend/utils/mmgr/dsa.c (+3/-0 lines) download inline-1.patch
--- a/src/backend/utils/mmgr/dsa.c
+++ b/src/backend/utils/mmgr/dsa.c
@@ -727,4 +727,7 @@ dsa_allocate_extended(dsa_area *area, size_t size, int flags)
if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
+ {
elog(FATAL,
"dsa_allocate could not find %zu free pages", npages);
+ abort()
+ }
* Re: dsa_allocate() faliure
@ 2018-12-02 22:45 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 0 replies; 60+ messages in thread
From: Thomas Munro @ 2018-12-02 22:45 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Alvaro Herrera <alvherre@2ndquadrant.com>; Pg Hackers <pgsql-hackers@postgresql.org>
On Sat, Dec 1, 2018 at 9:46 AM Justin Pryzby <pryzby@telsasoft.com> wrote:
> elog(FATAL,
> "dsa_allocate could not find %zu free pages", npages);
> + abort()
If anyone can reproduce this problem with a debugger, it'd be
interesting to see the output of dsa_dump(area), and
FreePageManagerDump(segment_map->fpm). This error condition means
that get_best_segment() selected a segment from a segment bin that
holds segments with a certain minimum number of contiguous free pages
>= the requested number npages, but then FreePageManagerGet() found
that it didn't have npages of contiguous free memory after all when it
consulted the segment's btree of free space. Possible explanations
include: the segment bin lists are somehow messed up, the FPM in the
segment was corrupted by someone scribbling on free pages (which hold
the btree), the btree was corrupted by an incorrect sequence of
allocate/free calls (for example double frees, allocating from one
area and freeing to another etc), freepage.c fails to track its
largest size correctly.
There is a macro FPM_EXTRA_ASSERTS that can be defined to double-check
the largest contiguous page tracking. I have also been wondering
about a debug mode that would mprotect(PROT_READ) free pages when they
aren't being modified to detect unexpected writes, which should work
on systems that have 4k pages.
One thing I noticed is that it is failing on a "large" allocation,
where we go straight to the btree of 4k pages, but the equivalent code
where we allocate a superblock for "small" allocations doesn't report
the same kind of FATAL this-can't-happen error, it just fails the
allocation via the regular error path without explanation. I also
spotted a path that doesn't respect the DSA_ALLOC_NO_OOM flag (you get
a null pointer instead of an error). I should fix those
inconsistencies (draft patch attached), but those are incidental
problems AFAIK.
--
Thomas Munro
http://www.enterprisedb.com
Attachments:
fix-dsa-area-handling.patch (application/octet-stream, 1.4K) download
diff --git a/src/backend/utils/mmgr/dsa.c b/src/backend/utils/mmgr/dsa.c
index 9ed9fa3a661..e503575be62 100644
--- a/src/backend/utils/mmgr/dsa.c
+++ b/src/backend/utils/mmgr/dsa.c
@@ -693,7 +693,18 @@ dsa_allocate_extended(dsa_area *area, size_t size, int flags)
/* Obtain a span object. */
span_pointer = alloc_object(area, DSA_SCLASS_BLOCK_OF_SPANS);
if (!DsaPointerIsValid(span_pointer))
+ {
+ /* Raise error unless asked not to. */
+ if ((flags & DSA_ALLOC_NO_OOM) == 0)
+ {
+ ereport(ERROR,
+ (errcode(ERRCODE_OUT_OF_MEMORY),
+ errmsg("out of memory"),
+ errdetail("Failed on DSA request of size %zu.",
+ size)));
+ }
return InvalidDsaPointer;
+ }
LWLockAcquire(DSA_AREA_LOCK(area), LW_EXCLUSIVE);
@@ -1669,13 +1680,14 @@ ensure_active_superblock(dsa_area *area, dsa_area_pool *pool,
return false;
}
}
+ /*
+ * This shouldn't happen: get_best_segment() or make_new_segment()
+ * promised that we can successfully allocate npages.
+ */
if (!FreePageManagerGet(segment_map->fpm, npages, &first_page))
- {
- LWLockRelease(DSA_AREA_LOCK(area));
- if (size_class != DSA_SCLASS_BLOCK_OF_SPANS)
- dsa_free(area, span_pointer);
- return false;
- }
+ elog(FATAL,
+ "dsa_allocate could not find %zu free pages for superblock",
+ npages);
LWLockRelease(DSA_AREA_LOCK(area));
/* Compute the start of the superblock. */
* RE: dsa_allocate() faliure
@ 2019-01-24 14:44 Arne Roland <A.Roland@index.de>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Arne Roland @ 2019-01-24 14:44 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; Sand Stone <sand.m.stone@gmail.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
Hello,
I'm not sure whether this is connected at all, but I'm facing the same error with a generated query on postgres 10.6.
It works with parallel query disabled and gives "dsa_allocate could not find 7 free pages" otherwise.
I've attached query and strace. The table is partitioned on (o, date). It's not depended on the precise lists I'm using, while it obviously does depend on the fact that the optimizer chooses a parallel query.
Regards
Arne Roland
-----Original Message-----
From: Thomas Munro <thomas.munro@enterprisedb.com>
Sent: Friday, October 5, 2018 4:17 AM
To: Sand Stone <sand.m.stone@gmail.com>
Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org; Robert Haas <robertmhaas@gmail.com>
Subject: Re: dsa_allocate() faliure
On Wed, Aug 29, 2018 at 5:48 PM Sand Stone <sand.m.stone@gmail.com> wrote:
> I attached a query (and its query plan) that caused the crash: "dsa_allocate could not find 13 free pages" on one of the worker nodes. I anonymised the query text a bit. Interestingly, this time only one (same one) of the nodes is crashing. Since this is a production environment, I cannot get the stack trace. Once turned off parallel execution for this node. The whole query finished just fine. So the parallel query plan is from one of the nodes not crashed, hopefully the same plan would have been executed on the crashed node. In theory, every worker node has the same bits, and very similar data.
I wonder if this was a different symptom of the problem fixed here:
https://www.postgresql.org/message-id/flat/194c0706-c65b-7d81-ab32-2c248c3e2344%402ndquadrant.com
Can you still reproduce it on current master, REL_11_STABLE or REL_10_STABLE?
--
Thomas Munro
http://www.enterprisedb.com
Attachments:
strace.log (application/octet-stream, 435.5K) download
query.sql (application/octet-stream, 141.1K) download
^ permalink raw reply [nested|flat] 60+ messages in thread
* RE: dsa_allocate() faliure
@ 2019-01-28 13:50 Arne Roland <A.Roland@index.de>
parent: Arne Roland <A.Roland@index.de>
0 siblings, 1 reply; 60+ messages in thread
From: Arne Roland @ 2019-01-28 13:50 UTC (permalink / raw)
To: Arne Roland <A.Roland@index.de>; Thomas Munro <thomas.munro@enterprisedb.com>; Sand Stone <sand.m.stone@gmail.com>; +Cc: Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
Hello,
does anybody have any idea what goes wrong here? Is there some additional information that could be helpful?
All the best
Arne Roland
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-01-28 18:56 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Arne Roland <A.Roland@index.de>
0 siblings, 2 replies; 60+ messages in thread
From: Thomas Munro @ 2019-01-28 18:56 UTC (permalink / raw)
To: Arne Roland <A.Roland@index.de>; +Cc: Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
On Tue, Jan 29, 2019 at 2:50 AM Arne Roland <A.Roland@index.de> wrote:
> does anybody have any idea what goes wrong here? Is there some additional information that could be helpful?
Hi Arne,
This seems to be a bug; that error should not be reached. I wonder if
it is a different manifestation of the bug reported as #15585 (ie some
type of rare corruption). Are you able to reproduce this
consistently? Can you please show the query plan?
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-01-29 11:32 Fabio Isabettini <fisabettini@voipfuture.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 1 reply; 60+ messages in thread
From: Fabio Isabettini @ 2019-01-29 11:32 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
Hello,
we are facing a similar issue on a Production system using a Postgresql 10.6:
org.postgresql.util.PSQLException: ERROR: EXCEPTION on getstatistics ; ID: EXCEPTION on getstatistics_media ; ID: uidatareader.
run_query_media(2): [a1] REMOTE FATAL: dsa_allocate could not find 7 free pages
The query reads remotely (via pl/proxy) tables containing a lot of data (up to millions or rows for each table/node) after a remote “group by" returns to the caller “master” node only a few hundreds of rows from each “slave” node.
The tables are partitioned using the INHERITANCE method that we are using since years with no issue. All tables have the same columns structure and number, about 300 columns. In the query there are no join, only a variable set of partitions depending on the date range.
The “REMOTE FATAL” refers to the pl/proxy that runs on 2 different slaves, [a0] and [a1], nodes with identical configuration and database structure, but it seems to fail only on node [a1].
When we get the error if we reduce the date range and therefore the quantity of data read, the error disappears, the same if we set max_parallel_workers_per_gather = 0.
Obviously we cannot force the user to use short periods of time to avoid the error and so we have disabled the parallel query feature for the time being.
It is difficult to reproduce the issue because not always the user gets the error, furthermore re-running the same query in different moments/days it usually works. It is a kind of weird.
We would like not to stop the Production system and upgrade it to PG11. And even though would this guarantee a permanent fix?
Any suggestion?
Regards,
Fabio Isabettini
Voipfuture (Germany)
The failing node [a1] configuration:
OS: Centos 7 kernerl 3.10.0-862.11.6.el7.x86_64
Postgres: postgres-10.5-862.11.6.1
RAM: 256 GB (The main server containing the master node and [a0] node, the slave that has no issue, has 384 GB of RAM)
CPU cores: 32
shared_buffers = 64GB
max_worker_processes = 32
max_parallel_workers_per_gather = 8
max_parallel_workers = 32
> On 28. Jan 2019, at 19:56:01, Thomas Munro <thomas.munro@enterprisedb.com> wrote:
>
> On Tue, Jan 29, 2019 at 2:50 AM Arne Roland <A.Roland@index.de> wrote:
>> does anybody have any idea what goes wrong here? Is there some additional information that could be helpful?
>
> Hi Arne,
>
> This seems to be a bug; that error should not be reached. I wonder if
> it is a different manifestation of the bug reported as #15585 (ie some
> type of rare corruption). Are you able to reproduce this
> consistently? Can you please show the query plan?
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-01-30 03:13 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Fabio Isabettini <fisabettini@voipfuture.com>
0 siblings, 2 replies; 60+ messages in thread
From: Thomas Munro @ 2019-01-30 03:13 UTC (permalink / raw)
To: Fabio Isabettini <fisabettini@voipfuture.com>; +Cc: Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
On Tue, Jan 29, 2019 at 10:32 PM Fabio Isabettini
<fisabettini@voipfuture.com> wrote:
> we are facing a similar issue on a Production system using a Postgresql 10.6:
>
> org.postgresql.util.PSQLException: ERROR: EXCEPTION on getstatistics ; ID: EXCEPTION on getstatistics_media ; ID: uidatareader.
> run_query_media(2): [a1] REMOTE FATAL: dsa_allocate could not find 7 free pages
> We would like not to stop the Production system and upgrade it to PG11. And even though would this guarantee a permanent fix?
> Any suggestion?
Hi Fabio,
Thanks for your report. Could you please also show the query plan
that runs on the "remote" node (where the error occurred)?
There is no indication that upgrading to PG11 would help here. It
seems we have an undiagnosed bug (in 10 and 11), and so far no one has
been able to reproduce it at will. I personally have chewed a lot of
CPU time on several machines trying various plan shapes and not seen
this or the possibly related symptom from bug #15585 even once. But
we have about three reports of each of the two symptoms. One reporter
wrote to me off-list to say that they'd seen #15585 twice, the second
time by running the same query in a tight loop for 8 hours, and then
not seen it again in the past 3 weeks. Clearly there is issue needing
a fix here, but I don't yet know what it is.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-01-30 09:53 Fabio Isabettini <fisabettini@voipfuture.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 0 replies; 60+ messages in thread
From: Fabio Isabettini @ 2019-01-30 09:53 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
Hi Thomas,
it is a Production system and we don’t have permanent access to it.
Also to have an auto_explain feature always on, is not an option in production.
I will ask the customer to give us notice asap the error present itself to connect immediately and try to get a query plan.
Regards
Fabio Isabettini
www.voipfuture.com
> On 30. Jan 2019, at 04:13:14, Thomas Munro <thomas.munro@enterprisedb.com> wrote:
>
> On Tue, Jan 29, 2019 at 10:32 PM Fabio Isabettini
> <fisabettini@voipfuture.com> wrote:
>> we are facing a similar issue on a Production system using a Postgresql 10.6:
>>
>> org.postgresql.util.PSQLException: ERROR: EXCEPTION on getstatistics ; ID: EXCEPTION on getstatistics_media ; ID: uidatareader.
>> run_query_media(2): [a1] REMOTE FATAL: dsa_allocate could not find 7 free pages
>
>> We would like not to stop the Production system and upgrade it to PG11. And even though would this guarantee a permanent fix?
>> Any suggestion?
>
> Hi Fabio,
>
> Thanks for your report. Could you please also show the query plan
> that runs on the "remote" node (where the error occurred)?
>
> There is no indication that upgrading to PG11 would help here. It
> seems we have an undiagnosed bug (in 10 and 11), and so far no one has
> been able to reproduce it at will. I personally have chewed a lot of
> CPU time on several machines trying various plan shapes and not seen
> this or the possibly related symptom from bug #15585 even once. But
> we have about three reports of each of the two symptoms. One reporter
> wrote to me off-list to say that they'd seen #15585 twice, the second
> time by running the same query in a tight loop for 8 hours, and then
> not seen it again in the past 3 weeks. Clearly there is issue needing
> a fix here, but I don't yet know what it is.
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* RE: dsa_allocate() faliure
@ 2019-01-31 18:19 Arne Roland <A.Roland@index.de>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 1 reply; 60+ messages in thread
From: Arne Roland @ 2019-01-31 18:19 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
Hi Thomas,
this is reproducible, while it's highly sensitive to the change of plans (i.e. the precise querys that do break change with every new analyze). Disabling parallel query seems to solve the problem (as expected).
At some point even the simple query
select count(*) from test_tab where (o = '0' and date >= '30.01.2019'::date-interval '14 days' or o = '1' and date >= '30.01.2019'::date-interval '14 days') and coalesce(fid,fallback) >=6 and coalesce(fid,fallback) <=6
was reported to fail (with the same error) at the live database, but I wasn't able to obtain a plan, since it works again with the current live data (maybe autoanalyze is at fault here).
The table test_tab has roughly 70 children that inherit from it. The children and the corresponding indexes should be named like '%part%'.
I attached a query with a plan that fails on my test database.
I don't want to rule out the possibility that it could be related to #15585; at least both issues seem to be related to Parallel Bitmap and inheritance/partitioned tables, but the error occurs relatively quickly in my case and every one of my processes (the children and the master) are failing with 'FATAL: dsa_allocate could not find 7 free pages'.
Regards
Arne
Attachments:
explain1s.txt (text/plain, 1.4M) download
query1s.sql (application/octet-stream, 65.8K) download
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-01 18:08 Justin Pryzby <pryzby@telsasoft.com>
parent: Arne Roland <A.Roland@index.de>
0 siblings, 0 replies; 60+ messages in thread
From: Justin Pryzby @ 2019-02-01 18:08 UTC (permalink / raw)
To: Arne Roland <A.Roland@index.de>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
On Thu, Jan 31, 2019 at 06:19:54PM +0000, Arne Roland wrote:
> this is reproducible, while it's highly sensitive to the change of plans (i.e. the precise querys that do break change with every new analyze). Disabling parallel query seems to solve the problem (as expected).
> At some point even the simple query
> select count(*) from test_tab where (o = '0' and date >= '30.01.2019'::date-interval '14 days' or o = '1' and date >= '30.01.2019'::date-interval '14 days') and coalesce(fid,fallback) >=6 and coalesce(fid,fallback) <=6
> was reported to fail (with the same error) at the live database, but I wasn't able to obtain a plan, since it works again with the current live data (maybe autoanalyze is at fault here).
> The table test_tab has roughly 70 children that inherit from it. The children and the corresponding indexes should be named like '%part%'.
>
> I attached a query with a plan that fails on my test database.
Thanks - note that previously Thomas said:
On Mon, Dec 03, 2018 at 11:45:00AM +1300, Thomas Munro wrote:
> On Sat, Dec 1, 2018 at 9:46 AM Justin Pryzby <pryzby@telsasoft.com> wrote:
> > elog(FATAL,
> > "dsa_allocate could not find %zu free pages", npages);
> > + abort()
>
> If anyone can reproduce this problem with a debugger, it'd be
> interesting to see the output of dsa_dump(area), and
> FreePageManagerDump(segment_map->fpm). This error condition means
Are you able to cause the error in a test/devel/non-production environment to
run under a debugger, or could you compile with "abort();" after that elog() to
save a corefile ?
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-04 07:52 Jakub Glapa <jakub.glapa@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 2 replies; 60+ messages in thread
From: Jakub Glapa @ 2019-02-04 07:52 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
Hi Thomas,
I was one of the reporter in the early Dec last year.
I somehow dropped the ball and forgot about the issue.
Anyhow I upgraded the clusters to pg11.1 and nothing changed. I also have a
rule to coredump but a segfault does not happen while this is occurring.
I see the error showing up every night on 2 different servers. But it's a
bit of a heisenbug because If I go there now it won't be reproducible.
It was suggested by Justin Pryzby that I recompile pg src with his patch
that would cause a coredump.
But I don't feel comfortable doing this especially if I would have to run
this with prod data.
My question is. Can I do anything like increasing logging level or enable
some additional options?
It's a production server but I'm willing to sacrifice a bit of it's
performance if that would help.
--
regards,
pozdrawiam,
Jakub Glapa
On Wed, Jan 30, 2019 at 4:13 AM Thomas Munro <thomas.munro@enterprisedb.com>
wrote:
> On Tue, Jan 29, 2019 at 10:32 PM Fabio Isabettini
> <fisabettini@voipfuture.com> wrote:
> > we are facing a similar issue on a Production system using a Postgresql
> 10.6:
> >
> > org.postgresql.util.PSQLException: ERROR: EXCEPTION on getstatistics ;
> ID: EXCEPTION on getstatistics_media ; ID: uidatareader.
> > run_query_media(2): [a1] REMOTE FATAL: dsa_allocate could not find 7
> free pages
>
> > We would like not to stop the Production system and upgrade it to PG11.
> And even though would this guarantee a permanent fix?
> > Any suggestion?
>
> Hi Fabio,
>
> Thanks for your report. Could you please also show the query plan
> that runs on the "remote" node (where the error occurred)?
>
> There is no indication that upgrading to PG11 would help here. It
> seems we have an undiagnosed bug (in 10 and 11), and so far no one has
> been able to reproduce it at will. I personally have chewed a lot of
> CPU time on several machines trying various plan shapes and not seen
> this or the possibly related symptom from bug #15585 even once. But
> we have about three reports of each of the two symptoms. One reporter
> wrote to me off-list to say that they'd seen #15585 twice, the second
> time by running the same query in a tight loop for 8 hours, and then
> not seen it again in the past 3 weeks. Clearly there is issue needing
> a fix here, but I don't yet know what it is.
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-04 08:22 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
1 sibling, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-04 08:22 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
On Mon, Feb 4, 2019 at 6:52 PM Jakub Glapa <jakub.glapa@gmail.com> wrote:
> I see the error showing up every night on 2 different servers. But it's a bit of a heisenbug because If I go there now it won't be reproducible.
Huh. Ok well that's a lot more frequent that I thought. Is it always
the same query? Any chance you can get the plan? Are there more
things going on on the server, like perhaps concurrent parallel
queries?
> It was suggested by Justin Pryzby that I recompile pg src with his patch that would cause a coredump.
Small correction to Justin's suggestion: don't abort() after
elog(ERROR, ...), it'll never be reached.
> But I don't feel comfortable doing this especially if I would have to run this with prod data.
> My question is. Can I do anything like increasing logging level or enable some additional options?
> It's a production server but I'm willing to sacrifice a bit of it's performance if that would help.
If you're able to run a throwaway copy of your production database on
another system that you don't have to worry about crashing, you could
just replace ERROR with PANIC and run a high-speed loop of the query
that crashed in product, or something. This might at least tell us
whether it's reach that condition via something dereferencing a
dsa_pointer or something manipulating the segment lists while
allocating/freeing.
In my own 100% unsuccessful attempts to reproduce this I was mostly
running the same query (based on my guess at what ingredients are
needed), but perhaps it requires a particular allocation pattern that
will require more randomness to reach... hmm.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* RE: dsa_allocate() faliure
@ 2019-02-04 20:31 Arne Roland <A.Roland@index.de>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Arne Roland @ 2019-02-04 20:31 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Fabio Isabettini <fisabettini@voipfuture.com>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>; Robert Haas <robertmhaas@gmail.com>
It's definitely a quite a relatively complex pattern. The query I set you last time was minimal with respect to predicates (so removing any single one of the predicates converted that one into a working query).
> Huh. Ok well that's a lot more frequent that I thought. Is it always the same query? Any chance you can get the plan? Are there more things going on on the server, like perhaps concurrent parallel queries?
I had this bug occurring while I was the only one working on the server. I checked there was just one transaction with a snapshot at all and it was a autovacuum busy with a totally unrelated relation my colleague was working on.
The bug is indeed behaving like a ghost.
One child relation needed a few new rows to test a particular application a colleague of mine was working on. The insert triggered an autoanalyze and the explain changed slightly:
Besides row and cost estimates the change is that the line
Recheck Cond: (((COALESCE((fid)::bigint, fallback) ) >= 1) AND ((COALESCE((fid)::bigint, fallback) ) <= 1) AND (gid && '{853078,853080,853082}'::integer[]))
is now
Recheck Cond: ((gid && '{853078,853080,853082}'::integer[]) AND ((COALESCE((fid)::bigint, fallback) ) >= 1) AND ((COALESCE((fid)::bigint, fallback) ) <= 1))
and the error vanished.
I could try to hunt down another query by assembling seemingly random queries. I don't see a very clear pattern from the queries aborting with this error on our production servers. I'm not surprised that bug is had to chase on production servers. They usually are quite lively.
>If you're able to run a throwaway copy of your production database on another system that you don't have to worry about crashing, you could just replace ERROR with PANIC and run a high-speed loop of the query that crashed in product, or something. This might at least tell us whether it's reach that condition via something dereferencing a dsa_pointer or something manipulating the segment lists while allocating/freeing.
I could take a backup and restore the relevant tables on a throwaway system. You are just suggesting to replace line 728
elog(FATAL,
"dsa_allocate could not find %zu free pages", npages);
by
elog(PANIC,
"dsa_allocate could not find %zu free pages", npages);
correct? Just for my understanding: why would the shutdown of the whole instance create more helpful logging?
All the best
Arne
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-04 21:47 Justin Pryzby <pryzby@telsasoft.com>
parent: Arne Roland <A.Roland@index.de>
0 siblings, 0 replies; 60+ messages in thread
From: Justin Pryzby @ 2019-02-04 21:47 UTC (permalink / raw)
To: Arne Roland <A.Roland@index.de>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; pgsql-performance@lists.postgresql.org
On Mon, Feb 04, 2019 at 08:31:47PM +0000, Arne Roland wrote:
> I could take a backup and restore the relevant tables on a throwaway system. You are just suggesting to replace line 728
> elog(FATAL,
> "dsa_allocate could not find %zu free pages", npages);
> by
> elog(PANIC,
> "dsa_allocate could not find %zu free pages", npages);
> correct? Just for my understanding: why would the shutdown of the whole instance create more helpful logging?
You'd also start with pg_ctl -c, which would allow it to dump core, which could
be inspected with GDB to show a backtrace and other internals, which up to now
nobody (including myself) has been able to provide.
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-06 23:21 Justin Pryzby <pryzby@telsasoft.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
1 sibling, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2019-02-06 23:21 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; pgsql-hackers@lists.postgresql.org
Moving to -hackers, hopefully it doesn't confuse the list scripts too much.
On Mon, Feb 04, 2019 at 08:52:17AM +0100, Jakub Glapa wrote:
> I see the error showing up every night on 2 different servers. But it's a
> bit of a heisenbug because If I go there now it won't be reproducible.
Do you have query logging enabled ? If not, could you consider it on at least
one of those servers ? I'm interested to know what ELSE is running at the time
that query failed.
Perhaps you could enable query logging JUST for the interval of time that the
server usually errors ? The CSV logs can be imported to postgres for analysis.
You might do something like SELECT left(message,99),COUNT(1),max(session_id) FROM postgres_log WHERE log_time BETWEEN .. AND .. GROUP BY 1 ORDER BY 2;
And just maybe there'd be a query there that only runs once per day which would
allow reproducing the error at will. Or utility command like vacuum..
I think ideally you'd set:
log_statement = all
log_min_messages = info
log_destination = 'stderr,csvlog'
# stderr isn't important for this purpose, but I keep it set to capture crash messages, too
You should set these to something that works well at your site:
log_rotation_age = '2min'
log_rotation_size = '32MB'
I would normally set these, and I don't see any reason why you wouldn't set
them too:
log_checkpoints = on
log_lock_waits = on
log_temp_files = on
log_min_error_statement = notice
log_temp_files = 0
log_min_duration_statement = '9sec'
log_autovacuum_min_duration = '999sec'
And I would set these too but maybe you'd prefer to do something else:
log_directory = /var/log/postgresql
log_file_mode = 0640
log_filename = postgresql-%Y-%m-%d_%H%M%S.log
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-07 10:10 Jakub Glapa <jakub.glapa@gmail.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 1 reply; 60+ messages in thread
From: Jakub Glapa @ 2019-02-07 10:10 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; pgsql-hackers@lists.postgresql.org
> Do you have query logging enabled ? If not, could you consider it on at
least
one of those servers ? I'm interested to know what ELSE is running at the
time
that query failed.
Ok, I have configured that and will enable in the time window when the
errors usually occur. I'll report as soon as I have something.
--
regards,
pozdrawiam,
Jakub Glapa
On Thu, Feb 7, 2019 at 12:21 AM Justin Pryzby <pryzby@telsasoft.com> wrote:
> Moving to -hackers, hopefully it doesn't confuse the list scripts too much.
>
> On Mon, Feb 04, 2019 at 08:52:17AM +0100, Jakub Glapa wrote:
> > I see the error showing up every night on 2 different servers. But it's a
> > bit of a heisenbug because If I go there now it won't be reproducible.
>
> Do you have query logging enabled ? If not, could you consider it on at
> least
> one of those servers ? I'm interested to know what ELSE is running at the
> time
> that query failed.
>
> Perhaps you could enable query logging JUST for the interval of time that
> the
> server usually errors ? The CSV logs can be imported to postgres for
> analysis.
> You might do something like SELECT
> left(message,99),COUNT(1),max(session_id) FROM postgres_log WHERE log_time
> BETWEEN .. AND .. GROUP BY 1 ORDER BY 2;
> And just maybe there'd be a query there that only runs once per day which
> would
> allow reproducing the error at will. Or utility command like vacuum..
>
> I think ideally you'd set:
>
> log_statement = all
> log_min_messages = info
> log_destination = 'stderr,csvlog'
> # stderr isn't important for this purpose, but I keep it set to capture
> crash messages, too
>
> You should set these to something that works well at your site:
>
> log_rotation_age = '2min'
> log_rotation_size = '32MB'
>
> I would normally set these, and I don't see any reason why you wouldn't set
> them too:
>
> log_checkpoints = on
> log_lock_waits = on
> log_temp_files = on
> log_min_error_statement = notice
> log_temp_files = 0
> log_min_duration_statement = '9sec'
> log_autovacuum_min_duration = '999sec'
>
> And I would set these too but maybe you'd prefer to do something else:
>
> log_directory = /var/log/postgresql
> log_file_mode = 0640
> log_filename = postgresql-%Y-%m-%d_%H%M%S.log
>
> Justin
>
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-07 17:49 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Jakub Glapa <jakub.glapa@gmail.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-07 17:49 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Thu, Feb 7, 2019 at 9:10 PM Jakub Glapa <jakub.glapa@gmail.com> wrote:
> > Do you have query logging enabled ? If not, could you consider it on at least
> one of those servers ? I'm interested to know what ELSE is running at the time
> that query failed.
>
> Ok, I have configured that and will enable in the time window when the errors usually occur. I'll report as soon as I have something.
I don't have the answer yet but I have some progress: I finally
reproduced the "could not find %d free pages" error by running lots of
concurrent parallel queries. Will investigate.
Set up:
create table foo (p int, a int, b int) partition by list (p);
create table foo_1 partition of foo for values in (1);
create table foo_2 partition of foo for values in (2);
create table foo_3 partition of foo for values in (3);
alter table foo_1 set (parallel_workers = 4);
alter table foo_2 set (parallel_workers = 4);
alter table foo_3 set (parallel_workers = 4);
insert into foo
select generate_series(1, 10000000)::int % 3 + 1,
generate_series(1, 10000000)::int % 50,
generate_series(1, 10000000)::int % 50;
create index on foo_1(a);
create index on foo_2(a);
create index on foo_3(a);
create index on foo_1(b);
create index on foo_2(b);
create index on foo_3(b);
analyze;
Then I ran three copies of :
#!/bin/sh
(
echo "set max_parallel_workers_per_gather = 4;"
for I in `seq 1 100000`; do
echo "explain analyze select count(*) from foo where a between 5
and 6 or b between 5 and 6;"
done
) | psql postgres
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-08 02:29 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-08 02:29 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Fri, Feb 8, 2019 at 4:49 AM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> I don't have the answer yet but I have some progress: I finally
> reproduced the "could not find %d free pages" error by running lots of
> concurrent parallel queries. Will investigate.
Sometimes FreeManagerPutInternal() returns a
number-of-contiguous-pages-created-by-this-insertion that is too large
by one. If this happens to be a new max-number-of-contiguous-pages,
it causes trouble some arbitrary time later because the max is wrong
and this FPM cannot satisfy a request that large, and it may not be
recomputed for some time because the incorrect value prevents
recomputation. Not sure yet if this is due to the lazy computation
logic or a plain old fence-post error in the btree consolidation code
or something else.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-09 10:21 Robert Haas <robertmhaas@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Robert Haas @ 2019-02-09 10:21 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Fri, Feb 8, 2019 at 8:00 AM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> Sometimes FreeManagerPutInternal() returns a
> number-of-contiguous-pages-created-by-this-insertion that is too large
> by one. If this happens to be a new max-number-of-contiguous-pages,
> it causes trouble some arbitrary time later because the max is wrong
> and this FPM cannot satisfy a request that large, and it may not be
> recomputed for some time because the incorrect value prevents
> recomputation. Not sure yet if this is due to the lazy computation
> logic or a plain old fence-post error in the btree consolidation code
> or something else.
I spent a long time thinking about this and starting at code this
afternoon, but I didn't really come up with much of anything useful.
It seems like a strange failure mode, because
FreePageManagerPutInternal() normally just returns its third argument
unmodified. The only cases where anything else happens are the ones
where we're able to consolidate the returned span with a preceding or
following span, and I'm scratching my head as to how that logic could
be wrong, especially since it also has some Assert() statements that
seem like they would detect the kinds of inconsistencies that would
lead to trouble. For example, if we somehow ended up with two spans
that (improperly) overlapped, we'd trip an Assert(). And if that
didn't happen -- because we're not in an Assert-enabled build -- the
code is written so that it only relies on the npages value of the last
of the consolidated scans, so an error in the npages value of one of
the earlier spans would just get fixed up.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-09 20:24 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Robert Haas <robertmhaas@gmail.com>
0 siblings, 2 replies; 60+ messages in thread
From: Thomas Munro @ 2019-02-09 20:24 UTC (permalink / raw)
To: Robert Haas <robertmhaas@gmail.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sat, Feb 9, 2019 at 9:21 PM Robert Haas <robertmhaas@gmail.com> wrote:
> On Fri, Feb 8, 2019 at 8:00 AM Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
> > Sometimes FreeManagerPutInternal() returns a
> > number-of-contiguous-pages-created-by-this-insertion that is too large
> > by one. [...]
>
> I spent a long time thinking about this and starting at code this
> afternoon, but I didn't really come up with much of anything useful.
> It seems like a strange failure mode, because
> FreePageManagerPutInternal() normally just returns its third argument
> unmodified. [...]
Bleugh. Yeah. What I said before wasn't quite right. The value
returned by FreePageManagerPutInternal() is actually correct at the
moment it is returned, but it ceases to be correct immediately
afterwards if the following call to FreePageBtreeCleanup() happens to
reduce the size of that particular span. The problem is that we
clobber fpm->contiguous_pages with the earlier (and by now incorrect)
value that we were holding in a local variable.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-09 21:06 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-09 21:06 UTC (permalink / raw)
To: Robert Haas <robertmhaas@gmail.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 7:24 AM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> On Sat, Feb 9, 2019 at 9:21 PM Robert Haas <robertmhaas@gmail.com> wrote:
> > On Fri, Feb 8, 2019 at 8:00 AM Thomas Munro
> > <thomas.munro@enterprisedb.com> wrote:
> > > Sometimes FreeManagerPutInternal() returns a
> > > number-of-contiguous-pages-created-by-this-insertion that is too large
> > > by one. [...]
> >
> > I spent a long time thinking about this and starting at code this
> > afternoon, but I didn't really come up with much of anything useful.
> > It seems like a strange failure mode, because
> > FreePageManagerPutInternal() normally just returns its third argument
> > unmodified. [...]
>
> Bleugh. Yeah. What I said before wasn't quite right. The value
> returned by FreePageManagerPutInternal() is actually correct at the
> moment it is returned, but it ceases to be correct immediately
> afterwards if the following call to FreePageBtreeCleanup() happens to
> reduce the size of that particular span.
... but why would it do that? I can reproduce cases where (for
example) FreePageManagerPutInternal() returns 179, and then
FreePageManagerLargestContiguous() returns 179, but then after
FreePageBtreeCleanup() it returns 178. At that point FreePageDump()
says:
btree depth 1:
77@0 l: 27(1) 78(178)
freelists:
1: 27
129: 78(178)
But at first glance it shouldn't be allocating pages, because it just
does consolidation to try to convert to singleton format, and then it
does recycle list cleanup using soft=true so that no allocation of
btree pages should occur.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-10 06:26 Robert Haas <robertmhaas@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
1 sibling, 0 replies; 60+ messages in thread
From: Robert Haas @ 2019-02-10 06:26 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 1:55 AM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> Bleugh. Yeah. What I said before wasn't quite right. The value
> returned by FreePageManagerPutInternal() is actually correct at the
> moment it is returned, but it ceases to be correct immediately
> afterwards if the following call to FreePageBtreeCleanup() happens to
> reduce the size of that particular span. The problem is that we
> clobber fpm->contiguous_pages with the earlier (and by now incorrect)
> value that we were holding in a local variable.
Yeah, I had similar bugs to that during the initial development work I
did on freepage.c, and that's why I got rid of some lazy recomputation
thing that I had tried at some point. The version that got committed
brought that back again, but possibly it's got the same kind of
problem.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-10 06:40 Robert Haas <robertmhaas@gmail.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 3 replies; 60+ messages in thread
From: Robert Haas @ 2019-02-10 06:40 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 2:37 AM Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> ... but why would it do that? I can reproduce cases where (for
> example) FreePageManagerPutInternal() returns 179, and then
> FreePageManagerLargestContiguous() returns 179, but then after
> FreePageBtreeCleanup() it returns 178. At that point FreePageDump()
> says:
>
> btree depth 1:
> 77@0 l: 27(1) 78(178)
> freelists:
> 1: 27
> 129: 78(178)
>
> But at first glance it shouldn't be allocating pages, because it just
> does consolidation to try to convert to singleton format, and then it
> does recycle list cleanup using soft=true so that no allocation of
> btree pages should occur.
I think I see what's happening. At the moment the problem occurs,
there is no btree - there is only a singleton range. So
FreePageManagerInternal() takes the fpm->btree_depth == 0 branch and
then ends up in the section with the comment /* Not contiguous; we
need to initialize the btree. */. And that section, sadly, does not
respect the 'soft' flag, so kaboom. Something like the attached might
fix it.
Boy, I love FreePageManagerDump!
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Attachments:
dsa-allocate-btree-init-soft.patch (application/octet-stream, 598B) download
diff --git a/src/backend/utils/mmgr/freepage.c b/src/backend/utils/mmgr/freepage.c
index d110030b63..18c3c188e8 100644
--- a/src/backend/utils/mmgr/freepage.c
+++ b/src/backend/utils/mmgr/freepage.c
@@ -1526,6 +1526,8 @@ FreePageManagerPutInternal(FreePageManager *fpm, Size first_page, Size npages,
if (!relptr_is_null(fpm->btree_recycle))
root = FreePageBtreeGetRecycled(fpm);
+ else if (soft)
+ return 0; /* Should not allocate if soft. */
else if (FreePageManagerGetInternal(fpm, 1, &root_page))
root = (FreePageBtree *) fpm_page_to_pointer(base, root_page);
else
* Re: dsa_allocate() faliure
@ 2019-02-10 16:00 Justin Pryzby <pryzby@telsasoft.com>
parent: Robert Haas <robertmhaas@gmail.com>
2 siblings, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2019-02-10 16:00 UTC (permalink / raw)
To: Robert Haas <robertmhaas@gmail.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Jakub Glapa <jakub.glapa@gmail.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 12:10:52PM +0530, Robert Haas wrote:
> I think I see what's happening. At the moment the problem occurs,
> there is no btree - there is only a singleton range. So
> FreePageManagerInternal() takes the fpm->btree_depth == 0 branch and
> then ends up in the section with the comment /* Not contiguous; we
> need to initialize the btree. */. And that section, sadly, does not
> respect the 'soft' flag, so kaboom. Something like the attached might
> fix it.
I ran overnight with this patch, but all parallel processes ended up stuck in
the style of bug#15585. So that's either not the root cause, or there's a 2nd
issue.
https://www.postgresql.org/message-id/flat/15585-324ff6a93a18da46%40postgresql.org
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-10 16:11 Sergei Kornilov <sk@zsrv.org>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 1 reply; 60+ messages in thread
From: Sergei Kornilov @ 2019-02-10 16:11 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; Robert Haas <robertmhaas@gmail.com>; +Cc: Thomas Munro <thomas.munro@enterprisedb.com>; Jakub Glapa <jakub.glapa@gmail.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <a.roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Hi
> I ran overnight with this patch, but all parallel processes ended up stuck in
> the style of bug#15585. So that's either not the root cause, or there's a 2nd
> issue.
Maybe i missed something in this discussion, but you can reproduce bug#15585? How? With this testcase: https://www.postgresql.org/message-id/CAEepm%3D1MvOE-Sfv1chudx5KEmw_qHYrj8F9Og_WmdBRhXSQ%2B%2Bw%40ma... ?
regards, Sergei
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-10 16:50 Justin Pryzby <pryzby@telsasoft.com>
parent: Sergei Kornilov <sk@zsrv.org>
0 siblings, 0 replies; 60+ messages in thread
From: Justin Pryzby @ 2019-02-10 16:50 UTC (permalink / raw)
To: Sergei Kornilov <sk@zsrv.org>; +Cc: Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@enterprisedb.com>; Jakub Glapa <jakub.glapa@gmail.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <a.roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 07:11:22PM +0300, Sergei Kornilov wrote:
> > I ran overnight with this patch, but all parallel processes ended up stuck in
> > the style of bug#15585. So that's either not the root cause, or there's a 2nd
> > issue.
>
> Maybe i missed something in this discussion, but you can reproduce bug#15585? How? With this testcase: https://www.postgresql.org/message-id/CAEepm%3D1MvOE-Sfv1chudx5KEmw_qHYrj8F9Og_WmdBRhXSQ%2B%2Bw%40ma... ?
By running the queued_alters query multiple times in a loop:
https://www.postgresql.org/message-id/20181231221734.GB25379%40telsasoft.com
I'm able to trigger dsa "ERROR"s with that query on a newly initdb cluster with
only that table. But I think some servers are more likely to hit it than
others.
I've only tripped on 15585 twice, and only while trying to trigger other DSA
bugs (the working hypothesis is that bug is 2ndary issue which happens after
hitting some other bug). And not consistently or quickly.
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-10 22:45 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Robert Haas <robertmhaas@gmail.com>
2 siblings, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-10 22:45 UTC (permalink / raw)
To: Robert Haas <robertmhaas@gmail.com>; +Cc: Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Sun, Feb 10, 2019 at 5:41 PM Robert Haas <robertmhaas@gmail.com> wrote:
> On Sun, Feb 10, 2019 at 2:37 AM Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
> > But at first glance it shouldn't be allocating pages, because it just
> > does consolidation to try to convert to singleton format, and then it
> > does recycle list cleanup using soft=true so that no allocation of
> > btree pages should occur.
>
> I think I see what's happening. At the moment the problem occurs,
> there is no btree - there is only a singleton range. So
> FreePageManagerInternal() takes the fpm->btree_depth == 0 branch and
> then ends up in the section with the comment /* Not contiguous; we
> need to initialize the btree. */. And that section, sadly, does not
> respect the 'soft' flag, so kaboom. Something like the attached might
> fix it.
Ouch. Yeah, that'd do it and matches the evidence. With this change,
I couldn't reproduce the problem after 90 minutes with a test case
that otherwise hits it within a couple of minutes.
Here's a patch with a commit message explaining the change.
It also removes an obsolete comment, which is in fact related. The
comment refers to an output parameter internal_pages_used, which must
have been used to report this exact phenomenon in an earlier
development version. But there is no such parameter in the committed
version, and instead there is the soft flag to prevent internal
allocation. I have no view on which approach is best, but yeah, if
we're using a soft flag, it has to work reliably.
This brings us to a difficult choice: we're about to cut a new
release, and this could in theory be included. Even though the fix is
quite convincing, it doesn't seem wise to change such complicated code
at the last minute, and I know from an off-list chat that that is also
Robert's view. So I'll wait until after the release, and we'll have
to live with the bug for another 3 months.
Note that this patch addresses the error "dsa_allocate could not find
%zu free pages". (The error "dsa_area could not attach to segment" is
something else and apparently rarer.)
> Boy, I love FreePageManagerDump!
Yeah. And I love reproducible bugs.
--
Thomas Munro
http://www.enterprisedb.com
Attachments:
0001-Fix-freepage.c-bug-that-causes-rare-dsa_allocate-fai.patch (application/octet-stream, 2.3K) download
From 744bbad5c865d4accfca9003a2ff1ec0172312d8 Mon Sep 17 00:00:00 2001
From: Thomas Munro <thomas.munro@enterprisedb.com>
Date: Mon, 11 Feb 2019 10:11:39 +1300
Subject: [PATCH] Fix freepage.c bug that causes rare dsa_allocate() failures.
In a corner case, a btree page was allocated during a clean-up operation
that could cause the book-keeping of the largest contiguous span of free
space to get out of whack. That was supposed to be prevented by the use
of the "soft" flag to avoid allocating internal pages during incidental
clean-up work, but the flag was ignored in the case where the FPM was
promoted from singleton format to btree format. Repair.
Remove an obsolete comment in passing.
Author: Robert Haas
Diagnosed-by: Robert Haas and Thomas Munro
Reported-by: Justin Pryzby, Rick Otten, Sand Stone, Arne Roland and others
Discussion: https://postgr.es/m/CAMAYy4%2Bw3NTBM5JLWFi8twhWK4%3Dk_5L4nV5%2BbYDSPu8r4b97Zg%40mail.gmail.com
---
src/backend/utils/mmgr/freepage.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)
diff --git a/src/backend/utils/mmgr/freepage.c b/src/backend/utils/mmgr/freepage.c
index d110030b63..9257235001 100644
--- a/src/backend/utils/mmgr/freepage.c
+++ b/src/backend/utils/mmgr/freepage.c
@@ -1470,9 +1470,7 @@ FreePageManagerGetInternal(FreePageManager *fpm, Size npages, Size *first_page)
* pages; if false, do it always. Returns 0 if the soft flag caused the
* insertion to be skipped, or otherwise the size of the contiguous span
* created by the insertion. This may be larger than npages if we're able
- * to consolidate with an adjacent range. *internal_pages_used is set to
- * true if the btree allocated pages for internal purposes, which might
- * invalidate the current largest run requiring it to be recomputed.
+ * to consolidate with an adjacent range.
*/
static Size
FreePageManagerPutInternal(FreePageManager *fpm, Size first_page, Size npages,
@@ -1526,6 +1524,8 @@ FreePageManagerPutInternal(FreePageManager *fpm, Size first_page, Size npages,
if (!relptr_is_null(fpm->btree_recycle))
root = FreePageBtreeGetRecycled(fpm);
+ else if (soft)
+ return 0; /* Should not allocate if soft. */
else if (FreePageManagerGetInternal(fpm, 1, &root_page))
root = (FreePageBtree *) fpm_page_to_pointer(base, root_page);
else
--
2.20.1
* Re: dsa_allocate() faliure
@ 2019-02-10 23:33 Tom Lane <tgl@sss.pgh.pa.us>
parent: Robert Haas <robertmhaas@gmail.com>
2 siblings, 2 replies; 60+ messages in thread
From: Tom Lane @ 2019-02-10 23:33 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Thomas Munro <thomas.munro@enterprisedb.com> writes:
> This brings us to a difficult choice: we're about to cut a new
> release, and this could in theory be included. Even though the fix is
> quite convincing, it doesn't seem wise to change such complicated code
> at the last minute, and I know from an off-list chat that that is also
> Robert's view.
Yeah ... at this point we're just too close to the release deadline,
I'm afraid, even though the fix *looks* pretty safe. Not worth the risk
given that this seems to be a low-probability bug.
I observe from
https://coverage.postgresql.org/src/backend/utils/mmgr/freepage.c.gcov.html
that the edge cases in this function aren't too well exercised by
our regression tests, meaning that the buildfarm might not prove
much either way about the correctness of this patch. That is one
factor pushing me to think we shouldn't risk it. But, taking a
longer view, is that something that's practical to improve?
> So I'll wait until after the release, and we'll have
> to live with the bug for another 3 months.
Check. Please hold off committing until you see the release tags
appear, probably late Tuesday my time / Wednesday noonish yours.
regards, tom lane
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-11 00:02 Justin Pryzby <pryzby@telsasoft.com>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2019-02-11 00:02 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Mon, Feb 11, 2019 at 09:45:07AM +1100, Thomas Munro wrote:
> Ouch. Yeah, that'd do it and matches the evidence. With this change,
> I couldn't reproduce the problem after 90 minutes with a test case
> that otherwise hits it within a couple of minutes.
...
> Note that this patch addresses the error "dsa_allocate could not find
> %zu free pages". (The error "dsa_area could not attach to segment" is
> something else and apparently rarer.)
"could not attach" is the error reported early this morning while
stress-testing this patch with queued_alters queries in loops, so that's
consistent with your understanding. And I guess it preceded getting stuck on
lock; although I don't how long between the first happened and the second, I'm
guess not long and perhaps immedidately; since the rest of the processes were
all stuck as in bug#15585 rather than ERRORing once every few minutes.
I mentioned that "could not attach to segment" occurs in leader either/or
parallel worker. And most of the time causes an ERROR only, and doesn't wedge
all future parallel workers. Maybe bug#15585 "wedged" state maybe only occurs
after some pattern of leader+worker failures (?) I've just triggered bug#15585
again, but if there's a pattern, I don't see it.
Please let me know whether you're able to reproduce the "not attach" bug using
simultaneous loops around the queued_alters query; it's easy here.
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-11 00:11 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 0 replies; 60+ messages in thread
From: Thomas Munro @ 2019-02-11 00:11 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Mon, Feb 11, 2019 at 11:02 AM Justin Pryzby <pryzby@telsasoft.com> wrote:
> On Mon, Feb 11, 2019 at 09:45:07AM +1100, Thomas Munro wrote:
> > Ouch. Yeah, that'd do it and matches the evidence. With this change,
> > I couldn't reproduce the problem after 90 minutes with a test case
> > that otherwise hits it within a couple of minutes.
> ...
> > Note that this patch addresses the error "dsa_allocate could not find
> > %zu free pages". (The error "dsa_area could not attach to segment" is
> > something else and apparently rarer.)
>
> "could not attach" is the error reported early this morning while
> stress-testing this patch with queued_alters queries in loops, so that's
> consistent with your understanding. And I guess it preceded getting stuck on
> lock; although I don't how long between the first happened and the second, I'm
> guess not long and perhaps immedidately; since the rest of the processes were
> all stuck as in bug#15585 rather than ERRORing once every few minutes.
>
> I mentioned that "could not attach to segment" occurs in leader either/or
> parallel worker. And most of the time causes an ERROR only, and doesn't wedge
> all future parallel workers. Maybe bug#15585 "wedged" state maybe only occurs
> after some pattern of leader+worker failures (?) I've just triggered bug#15585
> again, but if there's a pattern, I don't see it.
>
> Please let me know whether you're able to reproduce the "not attach" bug using
> simultaneous loops around the queued_alters query; it's easy here.
I haven't ever managed to reproduce that one yet. It's great you have
a reliable repro... Let's discuss it on the #15585 thread.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-11 00:24 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 1 reply; 60+ messages in thread
From: Thomas Munro @ 2019-02-11 00:24 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Mon, Feb 11, 2019 at 10:33 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I observe from
>
> https://coverage.postgresql.org/src/backend/utils/mmgr/freepage.c.gcov.html
>
> that the edge cases in this function aren't too well exercised by
> our regression tests, meaning that the buildfarm might not prove
> much either way about the correctness of this patch. That is one
> factor pushing me to think we shouldn't risk it. But, taking a
> longer view, is that something that's practical to improve?
Yeah. This is a nice example of code that really deserves unit tests
written in C. Could be good motivation to built the infrastructure I
mentioned here:
https://www.postgresql.org/message-id/flat/CAEepm%3D2heu%2B5zwB65jWap3XY-UP6PpJZiKLQRSV2UQH9BmVRXQ%4...
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-11 01:22 Tom Lane <tgl@sss.pgh.pa.us>
parent: Thomas Munro <thomas.munro@enterprisedb.com>
0 siblings, 0 replies; 60+ messages in thread
From: Tom Lane @ 2019-02-11 01:22 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@enterprisedb.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Mon, Feb 11, 2019 at 10:33 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> I observe from
>> https://coverage.postgresql.org/src/backend/utils/mmgr/freepage.c.gcov.html
>> that the edge cases in this function aren't too well exercised by
>> our regression tests, meaning that the buildfarm might not prove
>> much either way about the correctness of this patch. That is one
>> factor pushing me to think we shouldn't risk it. But, taking a
>> longer view, is that something that's practical to improve?
> Yeah. This is a nice example of code that really deserves unit tests
> written in C. Could be good motivation to built the infrastructure I
> mentioned here:
> https://www.postgresql.org/message-id/flat/CAEepm%3D2heu%2B5zwB65jWap3XY-UP6PpJZiKLQRSV2UQH9BmVRXQ%4...
Meh. I think if you hold out for that, you're going to be waiting a
long time. I was thinking more along the lines of making a test API
in src/test/modules/, akin to what we've got for predtest or rbtree.
regards, tom lane
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-13 00:52 Thomas Munro <thomas.munro@enterprisedb.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 0 replies; 60+ messages in thread
From: Thomas Munro @ 2019-02-13 00:52 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Robert Haas <robertmhaas@gmail.com>; Jakub Glapa <jakub.glapa@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Fabio Isabettini <fisabettini@voipfuture.com>; Arne Roland <A.Roland@index.de>; Sand Stone <sand.m.stone@gmail.com>; Rick Otten <rottenwindfish@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
On Mon, Feb 11, 2019 at 10:33 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Thomas Munro <thomas.munro@enterprisedb.com> writes:
> > So I'll wait until after the release, and we'll have
> > to live with the bug for another 3 months.
>
> Check. Please hold off committing until you see the release tags
> appear, probably late Tuesday my time / Wednesday noonish yours.
Pushed.
--
Thomas Munro
http://www.enterprisedb.com
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-17 22:21 Justin Pryzby <pryzby@telsasoft.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
1 sibling, 1 reply; 60+ messages in thread
From: Justin Pryzby @ 2019-02-17 22:21 UTC (permalink / raw)
To: Jakub Glapa <jakub.glapa@gmail.com>; +Cc: pgsql-performance@postgresql.org, Thomas Munro <thomas.munro@enterprisedb.com>
Hi,
On Mon, Nov 26, 2018 at 09:52:07AM -0600, Justin Pryzby wrote:
> Hi, thanks for following through.
>
> On Mon, Nov 26, 2018 at 04:38:35PM +0100, Jakub Glapa wrote:
> > I had a look at dmesg and indeed I see something like:
> >
> > postgres[30667]: segfault at 0 ip 0000557834264b16 sp 00007ffc2ce1e030
> > error 4 in postgres[557833db7000+6d5000]
>
> That's useful, I think "at 0" means a null pointer dereferenced.
Thomas fixed several bugs in DSA, which will be in next release, postgres 10.8
and 11.3.
However that doesn't explain the segfault you saw, and I don't see anything
which looks relevant changed since in 10.5.
If you still see that using the latest minor release (10.7), please try to
capture a core file and send a backtrace with a new thread on pgsql-hackers.
Thanks,
Justin
^ permalink raw reply [nested|flat] 60+ messages in thread
* Re: dsa_allocate() faliure
@ 2019-02-18 09:11 Jakub Glapa <jakub.glapa@gmail.com>
parent: Justin Pryzby <pryzby@telsasoft.com>
0 siblings, 0 replies; 60+ messages in thread
From: Jakub Glapa @ 2019-02-18 09:11 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: pgsql-performance@postgresql.org, Thomas Munro <thomas.munro@enterprisedb.com>
Hi I just checked the dmesg.
The segfault I wrote about is the only one I see, dated Nov 24 last year.
Since then no other segfaults happened although dsa_allocated failures
happen daily.
I'll report if anything occurs.
I have the core dumping setup in place.
--
regards,
pozdrawiam,
Jakub Glapa
On Sun, Feb 17, 2019 at 11:21 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> Hi,
>
> On Mon, Nov 26, 2018 at 09:52:07AM -0600, Justin Pryzby wrote:
> > Hi, thanks for following through.
> >
> > On Mon, Nov 26, 2018 at 04:38:35PM +0100, Jakub Glapa wrote:
> > > I had a look at dmesg and indeed I see something like:
> > >
> > > postgres[30667]: segfault at 0 ip 0000557834264b16 sp 00007ffc2ce1e030
> > > error 4 in postgres[557833db7000+6d5000]
> >
> > That's useful, I think "at 0" means a null pointer dereferenced.
>
> Thomas fixed several bugs in DSA, which will be in next release, postgres
> 10.8
> and 11.3.
>
> However that doesn't explain the segfault you saw, and I don't see anything
> which looks relevant changed since in 10.5.
>
> If you still see that using the latest minor release (10.7), please try to
> capture a core file and send a backtrace with a new thread on
> pgsql-hackers.
>
> Thanks,
> Justin
>
^ permalink raw reply [nested|flat] 60+ messages in thread
end of thread, other threads:[~2019-02-18 09:11 UTC | newest]
Thread overview: 60+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2018-01-29 16:19 dsa_allocate() faliure Rick Otten <rottenwindfish@gmail.com>
2018-01-29 16:37 ` Tom Lane <tgl@sss.pgh.pa.us>
2018-01-29 20:52 ` Thomas Munro <thomas.munro@enterprisedb.com>
2018-01-29 21:35 ` Rick Otten <rottenwindfish@gmail.com>
2018-05-23 04:10 ` Sand Stone <sand.m.stone@gmail.com>
2018-05-23 04:44 ` Thomas Munro <thomas.munro@enterprisedb.com>
2018-05-23 14:06 ` Sand Stone <sand.m.stone@gmail.com>
2018-08-15 20:32 ` Sand Stone <sand.m.stone@gmail.com>
2018-08-15 22:42 ` Thomas Munro <thomas.munro@enterprisedb.com>
2018-08-25 14:46 ` Sand Stone <sand.m.stone@gmail.com>
2018-08-29 04:44 ` Sand Stone <sand.m.stone@gmail.com>
2018-10-05 02:16 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-01-24 14:44 ` Arne Roland <A.Roland@index.de>
2019-01-28 13:50 ` Arne Roland <A.Roland@index.de>
2019-01-28 18:56 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-01-29 11:32 ` Fabio Isabettini <fisabettini@voipfuture.com>
2019-01-30 03:13 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-01-30 09:53 ` Fabio Isabettini <fisabettini@voipfuture.com>
2019-02-04 07:52 ` Jakub Glapa <jakub.glapa@gmail.com>
2019-02-04 08:22 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-04 20:31 ` Arne Roland <A.Roland@index.de>
2019-02-04 21:47 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-06 23:21 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-07 10:10 ` Jakub Glapa <jakub.glapa@gmail.com>
2019-02-07 17:49 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-08 02:29 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-09 10:21 ` Robert Haas <robertmhaas@gmail.com>
2019-02-09 20:24 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-09 21:06 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-10 06:40 ` Robert Haas <robertmhaas@gmail.com>
2019-02-10 16:00 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-10 16:11 ` Sergei Kornilov <sk@zsrv.org>
2019-02-10 16:50 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-10 22:45 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-11 00:02 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-11 00:11 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-10 23:33 ` Tom Lane <tgl@sss.pgh.pa.us>
2019-02-11 00:24 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-11 01:22 ` Tom Lane <tgl@sss.pgh.pa.us>
2019-02-13 00:52 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-10 06:26 ` Robert Haas <robertmhaas@gmail.com>
2019-01-31 18:19 ` Arne Roland <A.Roland@index.de>
2019-02-01 18:08 ` Justin Pryzby <pryzby@telsasoft.com>
2018-11-13 13:08 Re: dsa_allocate() faliure Jakub Glapa <jakub.glapa@gmail.com>
2018-11-21 14:26 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-22 16:09 ` Justin Pryzby <pryzby@telsasoft.com>
2018-11-23 14:31 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-23 16:10 ` Justin Pryzby <pryzby@telsasoft.com>
2018-11-26 15:26 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-26 15:38 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-26 15:52 ` Justin Pryzby <pryzby@telsasoft.com>
2018-11-26 16:00 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-26 18:45 ` Alvaro Herrera <alvherre@2ndquadrant.com>
2018-11-27 03:00 ` Thomas Munro <thomas.munro@enterprisedb.com>
2018-11-27 08:02 ` Thomas Munro <thomas.munro@enterprisedb.com>
2018-11-30 19:20 ` Jakub Glapa <jakub.glapa@gmail.com>
2018-11-30 20:46 ` Justin Pryzby <pryzby@telsasoft.com>
2018-12-02 22:45 ` Thomas Munro <thomas.munro@enterprisedb.com>
2019-02-17 22:21 ` Justin Pryzby <pryzby@telsasoft.com>
2019-02-18 09:11 ` Jakub Glapa <jakub.glapa@gmail.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox