[sqlsmith] Failed assertion in BecomeLockGroupLeader

On Fri, Apr 29, 2016 at 12:01 PM, Andreas Seltenreich <seltenreich@gmx.de>
wrote:

Hi,

tonight's sqlsmith run yielded another core dump:

TRAP: FailedAssertion("!(MyProc->lockGroupLeader == ((void *)0))", File:

"proc.c", Line: 1787)

I couldn't identifiy a query for it though: debug_query_string is empty.
Additionally, the offending query was not reported in the error context
as it typically is for non-parallel executor crashes.

From callstack below, it is clear that the reason for core dump is that
Gather node is pushed below another Gather node which makes worker execute
the Gather node. Currently there is no support in workers to launch
another workers and ideally such a plan should not be generated. It will
be helpful if you can find the offending query or plan corresponding to it?

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

Amit Kapila wrote:

On Fri, Apr 29, 2016 at 12:01 PM, Andreas Seltenreich <seltenreich@gmx.de>
wrote:

I couldn't identifiy a query for it though: debug_query_string is empty.
Additionally, the offending query was not reported in the error context
as it typically is for non-parallel executor crashes.

From callstack below, it is clear that the reason for core dump is that
Gather node is pushed below another Gather node which makes worker execute
the Gather node. Currently there is no support in workers to launch
another workers and ideally such a plan should not be generated. It will
be helpful if you can find the offending query or plan corresponding to it?

So I suppose the PID of the process starting the workers should be in
the stack somewhere. With that one should be able to attach to that
process and get another stack trace. I'm curious on whether you would
need to have started the server with "postgres -T" in order to be able
to get a coordinated code dump from both processes. The
debug_query_string would be found in the leader, I suppose.

--
�lvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

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

On 29 April 2016 at 08:31, Andreas Seltenreich <seltenreich@gmx.de> wrote:

Hi,

tonight's sqlsmith run yielded another core dump:

TRAP: FailedAssertion("!(MyProc->lockGroupLeader == ((void *)0))", File:
"proc.c", Line: 1787)

I couldn't identifiy a query for it though: debug_query_string is empty.
Additionally, the offending query was not reported in the error context
as it typically is for non-parallel executor crashes.

It's good that the input is fuzzed, but there needs to be a way to re-run
identical fuzzing or a way to backtrack to find what broke. Not much point
finding bugs we can't identify later.

--
Simon Riggs http://www.2ndQuadrant.com/
<http://www.2ndquadrant.com/&gt;
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Amit Kapila <amit.kapila16@gmail.com> writes:

On Fri, Apr 29, 2016 at 12:01 PM, Andreas Seltenreich <seltenreich@gmx.de>
wrote:

tonight's sqlsmith run yielded another core dump:

TRAP: FailedAssertion("!(MyProc->lockGroupLeader == ((void *)0))", File:
"proc.c", Line: 1787)

I couldn't identifiy a query for it though: debug_query_string is empty.
Additionally, the offending query was not reported in the error context
as it typically is for non-parallel executor crashes.

From callstack below, it is clear that the reason for core dump is that
Gather node is pushed below another Gather node which makes worker execute
the Gather node. Currently there is no support in workers to launch
another workers and ideally such a plan should not be generated.

It might not be intentional. The bug we identified from Andreas' prior
report could be causing this: once a GatherPath's subpath has been freed,
that palloc chunk could be recycled into another GatherPath, or something
with a GatherPath in its substructure, leading to a plan of that shape.

It will
be helpful if you can find the offending query or plan corresponding to it?

I presume the lack of debug_query_string data is because nothing is
bothering to set debug_query_string in a worker process. Should that be
remedied? At the very least set it to "worker process", but it might be
worth copying over the full query from the parent side.

regards, tom lane

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

Alvaro Herrera writes:

Amit Kapila wrote:

It will be helpful if you can find the offending query or plan
corresponding to it?

So I suppose the PID of the process starting the workers should be in
the stack somewhere.

Ja, it's right on the top, but long gone by now…

With that one should be able to attach to that process and get another
stack trace. I'm curious on whether you would need to have started
the server with "postgres -T"

This sounds like it should work to capture more context when the
Assertion fails the next time. I have to purge the catalogs a bit
though to avoid stopping early on boring core dumps. Most of them are
currently caused by acl.c using text for syscache lookups and triggering
an NAMEDATALEN assertion.

E.g.: select has_language_privilege('smithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmith', smith');

thanks,
andreas

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

Simon Riggs writes:

It's good that the input is fuzzed, but there needs to be a way to re-run
identical fuzzing or a way to backtrack to find what broke. Not much point
finding bugs we can't identify later.

sqlsmith is deterministic and allows re-generating a sequence of random
queries with the --seed argument. Finding a testing methodology that
ensures a repeatable server-side is a harder problem though.

One would have to avoid touching any kind of concurrency, disable
autovacuum, autoanalyze and invoke explicit analyzes/vacuums in concert
with query generation. Further, one would have to avoid any kind of
concurrency while testing. Even then, 1% of the queries run into a
statement_timeout due to randomly generated excessive cross joins. If a
timeout just barely happens, it might not do so on the repeated run and
the deterministic state is gone from then on. I'm afraid this list is
not complete yet.

I didn't think the effort of creating this kind of clean-room testing
was worth it. If reports of failed assertions with backtrace without a
recipe to reproduce them are a nuisance, I'll avoid them in the future.

regards,
Andreas

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

On 2016-04-30 02:28:22 +0200, Andreas Seltenreich wrote:

This sounds like it should work to capture more context when the
Assertion fails the next time. I have to purge the catalogs a bit
though to avoid stopping early on boring core dumps. Most of them are
currently caused by acl.c using text for syscache lookups and triggering
an NAMEDATALEN assertion.

E.g.: select has_language_privilege('smithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmithsmith', smith');

Yuck. We got to fix those. Does anybody remember how these functions
came to use text instead of name for things that pretty clearly should
have accepted name (i.e. the objects not the priv string)?

Andres

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

On 2016-04-30 02:34:35 +0200, Andreas Seltenreich wrote:

I didn't think the effort of creating this kind of clean-room testing
was worth it. If reports of failed assertions with backtrace without a
recipe to reproduce them are a nuisance, I'll avoid them in the future.

It's obviously better to have a recipe for reproducing the issue, but I
think the reports are quite useful even without that.

Andres

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

On Fri, Apr 29, 2016 at 7:15 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Amit Kapila <amit.kapila16@gmail.com> writes:

On Fri, Apr 29, 2016 at 12:01 PM, Andreas Seltenreich <

seltenreich@gmx.de>

wrote:

tonight's sqlsmith run yielded another core dump:

TRAP: FailedAssertion("!(MyProc->lockGroupLeader == ((void *)0))",

File:

"proc.c", Line: 1787)

I couldn't identifiy a query for it though: debug_query_string is

empty.

Additionally, the offending query was not reported in the error context
as it typically is for non-parallel executor crashes.

From callstack below, it is clear that the reason for core dump is that
Gather node is pushed below another Gather node which makes worker

execute

the Gather node. Currently there is no support in workers to launch
another workers and ideally such a plan should not be generated.

It might not be intentional. The bug we identified from Andreas' prior
report could be causing this: once a GatherPath's subpath has been freed,
that palloc chunk could be recycled into another GatherPath, or something
with a GatherPath in its substructure, leading to a plan of that shape.

Yes, thats one possibility.

It will
be helpful if you can find the offending query or plan corresponding to

it?

I presume the lack of debug_query_string data is because nothing is
bothering to set debug_query_string in a worker process. Should that be
remedied? At the very least set it to "worker process",

Currently for the purpose of query descriptor in worker process, we are
using "<parallel_query>" (refer function ExecParallelGetQueryDesc()), so
that seems to be a better choice.

but it might be
worth copying over the full query from the parent side.

That would amount to couple of extra cycles considering we need to do it
for each worker, but OTOH it might be a useful debugging information in the
cases as reported in this thread. Do you see any broader use of passing
query string to worker?

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

On Sat, Apr 30, 2016 at 5:58 AM, Andreas Seltenreich <seltenreich@gmx.de>
wrote:

Alvaro Herrera writes:

Amit Kapila wrote:

It will be helpful if you can find the offending query or plan
corresponding to it?

So I suppose the PID of the process starting the workers should be in
the stack somewhere.

Ja, it's right on the top, but long gone by now…

With that one should be able to attach to that process and get another
stack trace. I'm curious on whether you would need to have started
the server with "postgres -T"

This sounds like it should work to capture more context when the
Assertion fails the next time.

Sounds good. So can we assume that you will try to get us the new report
with more information?

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

Amit Kapila writes:

On Sat, Apr 30, 2016 at 5:58 AM, Andreas Seltenreich <seltenreich@gmx.de> wrote:

This sounds like it should work to capture more context when the
Assertion fails the next time.

Sounds good. So can we assume that you will try to get us the new report
with more information?

Ja. I do have a busy weekend+week ahead though, so no holding of
breath.

regards
Andreas

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

Amit Kapila writes:

On Fri, Apr 29, 2016 at 7:15 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

but it might be worth copying over the full query from the parent
side.

That would amount to couple of extra cycles considering we need to do it
for each worker, but OTOH it might be a useful debugging information in the
cases as reported in this thread.

Maybe only do it in assertion-enabled builds when performance is an
issue?

regards,
andreas

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

On Fri, Apr 29, 2016 at 9:45 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

It will
be helpful if you can find the offending query or plan corresponding to it?

I presume the lack of debug_query_string data is because nothing is
bothering to set debug_query_string in a worker process. Should that be
remedied? At the very least set it to "worker process", but it might be
worth copying over the full query from the parent side.

I agree. I thought about doing that at one point, but I didn't quite
have the cycles and I wasn't sure how important it would be. The fact
that we're already hitting cases like this before we've even gone to
beta suggests that it's pretty important. I think it's worth the
extra cycles, even in non-cassert builds. Compared to the overhead of
cajoling the postmaster to fork a new process, the cost of this should
be trivial.

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

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

Amit Kapila writes:

Sounds good. So can we assume that you will try to get us the new report
with more information?

I don't see these crashes anymore in c1543a8. By the amount of fuzzing
done it should have happened a dozen times, so it's highly likely
something in 23b09e15..c1543a8 fixed it.

regards,
andreas

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

On Thu, May 5, 2016 at 4:11 PM, Andreas Seltenreich <seltenreich@gmx.de> wrote:

Amit Kapila writes:

Sounds good. So can we assume that you will try to get us the new report
with more information?

I don't see these crashes anymore in c1543a8. By the amount of fuzzing
done it should have happened a dozen times, so it's highly likely
something in 23b09e15..c1543a8 fixed it.

Hmm, I'd guess c45bf5751b6338488bd79ce777210285531da373 to be the most
likely candidate.

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

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

Robert Haas wrote:

On Thu, May 5, 2016 at 4:11 PM, Andreas Seltenreich <seltenreich@gmx.de> wrote:

Amit Kapila writes:

Sounds good. So can we assume that you will try to get us the new report
with more information?

I don't see these crashes anymore in c1543a8. By the amount of fuzzing
done it should have happened a dozen times, so it's highly likely
something in 23b09e15..c1543a8 fixed it.

Hmm, I'd guess c45bf5751b6338488bd79ce777210285531da373 to be the most
likely candidate.

I thought so too, but then that patch change things in the planner side,
but it seems to me that the reported crash is in the executor, unless I'm
misreading.

--
�lvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

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

Alvaro Herrera writes:

Robert Haas wrote:

On Thu, May 5, 2016 at 4:11 PM, Andreas Seltenreich <seltenreich@gmx.de> wrote:

I don't see these crashes anymore in c1543a8. By the amount of fuzzing
done it should have happened a dozen times, so it's highly likely
something in 23b09e15..c1543a8 fixed it.

Hmm, I'd guess c45bf5751b6338488bd79ce777210285531da373 to be the most
likely candidate.

I thought so too, but then that patch change things in the planner side,
but it seems to me that the reported crash is in the executor, unless I'm
misreading.

Tom had a theory in Message-ID: <12751.1461937508@sss.pgh.pa.us> on how
the planner bug could cause the executor crash.

regards,
Andreas

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