Thread: Bug #883: explain analyze causes postgres to die

Bug #883: explain analyze causes postgres to die

From
pgsql-bugs@postgresql.org
Date:
Christopher Hodson (nerf@distributed.net) reports a bug with a severity of 3
The lower the number the more severe it is.

Short Description
explain analyze causes postgres to die

Long Description
running explain analyze on the code below causes postgres to crash.  See below for error messages.

                                version
-----------------------------------------------------------------------
 PostgreSQL 7.3.1 on i386-portbld-freebsd4.6.1, compiled by GCC 2.95.3

from psql (almost immediately):
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

the log has this to say:
2003-01-23 20:57:54 [29981]  LOG:  server process (pid 30037) was terminated by signal 11
2003-01-23 20:57:54 [29981]  LOG:  terminating any other active server processes
The connection to the server was lost. Attempting reset: 2003-01-23 20:57:54 [29981]  LOG:  all server processes
terminated;reinitializing shared memory and semaphores 
2003-01-23 20:57:54 [30051]  LOG:  connection received: host=[local]
2003-01-23 20:57:54 [30051]  FATAL:  The database system is starting up
Failed.
!# 2003-01-23 20:57:54 [30050]  LOG:  database system was interrupted at 2003-01-23 20:40:44 GMT
2003-01-23 20:57:54 [30050]  LOG:  checkpoint record is at 26/201BAC04
2003-01-23 20:57:54 [30050]  LOG:  redo record is at 26/201BAC04; undo record is at 0/0; shutdown TRUE
2003-01-23 20:57:54 [30050]  LOG:  next transaction id: 5645; next oid: 78509014
2003-01-23 20:57:54 [30050]  LOG:  database system was not properly shut down; automatic recovery in progress
2003-01-23 20:57:54 [30050]  LOG:  ReadRecord: record with zero length at 26/201BAC44
2003-01-23 20:57:54 [30050]  LOG:  redo is not required
2003-01-23 20:57:57 [30050]  LOG:  database system is ready

Sample Code
explain analyze INSERT INTO stubs(id, stub_id, nodecount, platform_id, return_count)
SELECT I.id, A.stub_id, L.nodecount, P.platform_id, count(*)
        FROM logdata L, id_lookup I, all_stubs A, platform P
        WHERE lower(L.email) = lower(I.email)
        AND L.stub_marks = A.stub_marks
        AND L.os_type = P.os_type
        AND L.cpu_type = P.cpu_type
        AND L.version = P.version
        GROUP BY I.id, A.stub_id, L.nodecount, P.platform_id

here are the results of 'explain' on the same query

Subquery Scan "*SELECT*"  (cost=9281796.01..9313773.17 rows=213181 width=155)
   ->  Aggregate  (cost=9281796.01..9313773.17 rows=213181 width=155)
         ->  Group  (cost=9281796.01..9308443.64 rows=2131811 width=155)
               ->  Sort  (cost=9281796.01..9287125.53 rows=2131811 width=155)
                     Sort Key: i.id, a.stub_id, l.nodecount, p.platform_id
                     ->  Nested Loop  (cost=2.75..8361073.78 rows=2131811 width=155)
                           ->  Nested Loop  (cost=2.75..1632538.08 rows=1083 width=101)
                                 ->  Hash Join  (cost=2.75..1626418.99 rows=1083 width=78)
                                       Hash Cond: ("outer".os_type = "inner".os_type)
                                       Join Filter: (("outer".cpu_type = "inner".cpu_type) AND ("outer"."version" =
"inner"."version"))
                                       ->  Seq Scan on logdata l  (cost=0.00..458727.96 rows=21230696 width=62)
                                       ->  Hash  (cost=2.40..2.40 rows=140 width=16)
                                             ->  Seq Scan on platform p  (cost=0.00..2.40 rows=140 width=16)
                                 ->  Index Scan using all_marks on all_stubs a  (cost=0.00..5.64 rows=1 width=23)
                                       Index Cond: ("outer".stub_marks = a.stub_marks)
                           ->  Index Scan using idlookup_email_lower on id_lookup i  (cost=0.00..6177.29 rows=1968
width=54)
                                 Index Cond: (lower(("outer".email)::text) = lower((i.email)::text))
(17 rows)


No file was uploaded with this report

Re: Bug #883: explain analyze causes postgres to die

From
Tom Lane
Date:
pgsql-bugs@postgresql.org writes:
> explain analyze causes postgres to die

Can't do much with this, since you have not provided a complete test
case.

            regards, tom lane

Re: Bug #883: explain analyze causes postgres to die

From
Neil Conway
Date:
On Thu, 2003-01-23 at 16:45, pgsql-bugs@postgresql.org wrote:
> running explain analyze on the code below causes postgres to crash.  See below for error messages.

Can you provide the schema for the tables involved in the query, please?

A backtrace from the core file created when the backend crashes would
also be helpful -- if you could also recompile with debugging symbols
(--enable-debug), that would be good.

Cheers,

Neil
--
Neil Conway <neilc@samurai.com> || PGP Key ID: DB3C29FC

Re: Bug #883: explain analyze causes postgres to die

From
"Chris Hodson"
Date:
I included the code in the "example code" box.  I'll include it again here.
If you need more info, just let me know.

I execute the command:
EXPLAIN ANALYZE INSERT INTO stubs(id, stub_id, nodecount, platform_id,
return_count)
SELECT I.id, A.stub_id, L.nodecount, P.platform_id, count(*)
        FROM logdata L, id_lookup I, all_stubs A, platform P
        WHERE lower(L.email) = lower(I.email)
        AND L.stub_marks = A.stub_marks
        AND L.os_type = P.os_type
        AND L.cpu_type = P.cpu_type
        AND L.version = P.version
        GROUP BY I.id, A.stub_id, L.nodecount, P.platform_id;

and get back(from psql):
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
The connection to the server was lost. Attempting reset

The log shows:
2003-01-24 07:29:35 [36633]  LOG:  server process (pid 36657) was terminated
by signal 11
2003-01-24 07:29:35 [36633]  LOG:  terminating any other active server
processes
2003-01-24 07:29:35 [36633]  LOG:  all server processes terminated;
reinitializing shared memory and semaphores
2003-01-24 07:29:35 [36666]  LOG:  connection received: host=[local]
2003-01-24 07:29:35 [36666]  FATAL:  The database system is starting up
2003-01-24 07:29:35 [36665]  LOG:  database system was interrupted at
2003-01-24 07:23:52 GMT
2003-01-24 07:29:35 [36665]  LOG:  checkpoint record is at 26/2020EA78
2003-01-24 07:29:35 [36665]  LOG:  redo record is at 26/2020EA78; undo
record is at 0/0; shutdown TRUE
2003-01-24 07:29:35 [36665]  LOG:  next transaction id: 5758; next oid:
78509015
2003-01-24 07:29:35 [36665]  LOG:  database system was not properly shut
down; automatic recovery in progress
2003-01-24 07:29:35 [36665]  LOG:  ReadRecord: record with zero length at
26/2020EAB8
2003-01-24 07:29:35 [36665]  LOG:  redo is not required
2003-01-24 07:29:38 [36665]  LOG:  database system is ready

some info about the table:
             Table "public.logdata"
   Column   |         Type          | Modifiers
------------+-----------------------+-----------
 email      | character varying(64) |
 stub_marks | character varying(22) |
 nodecount  | bigint                |
 os_type    | integer               |
 cpu_type   | integer               |
 version    | integer               |
Indexes: logdata_cpu_version btree (cpu_type, "version"),
         logdata_platform btree (os_type, cpu_type, "version")

           Table "public.id_lookup"
  Column  |         Type          | Modifiers
----------+-----------------------+-----------
 email    | character varying(64) |
 id       | integer               |
 stats_id | integer               |
Indexes: idlookup_email_lower unique btree (lower(email)),
         idlookup_id btree (id)

                                    Table "public.all_stubs"
   Column   |         Type          |                         Modifiers
------------+-----------------------+---------------------------------------
--------------------
 stub_marks | character varying(22) | not null
 stub_id    | integer               | not null default
nextval('"all_stubs_stub_id_seq"'::text)
 project_id | smallint              | not null
Indexes: all_stubs_pkey primary key btree (stub_id),
         all_marks unique btree (stub_marks),
         all_stubproject_id unique btree (stub_id, project_id)

                                  Table "public.platform"
   Column    |  Type   |                             Modifiers
-------------+---------+----------------------------------------------------
---------------
 platform_id | integer | not null default
nextval('public.platform_platform_id_seq'::text)
 os_type     | integer | not null
 cpu_type    | integer | not null
 version     | integer | not null
Indexes: platform_pkey primary key btree (platform_id),
         platform_all btree (os_type, cpu_type, "version")

        Table "public.stubs"
    Column    |  Type   | Modifiers
--------------+---------+-----------
 id           | integer |
 stub_id      | integer |
 nodecount    | bigint  |
 platform_id  | integer |
 return_count | integer |

logdata:
  count
----------
 21230697
(1 row)

id_lookup:
 count
--------
 393614
(1 row)

all_stubs:
  count
----------
 26243933
(1 row)

platform:
 count
-------
   140
(1 row)

stubs:
 count
-------
     0
(1 row)

----- Original Message -----
From: "Tom Lane" <tgl@sss.pgh.pa.us>
To: <nerf@distributed.net>; <pgsql-bugs@postgresql.org>
Sent: Friday, January 24, 2003 12:28 AM
Subject: Re: [BUGS] Bug #883: explain analyze causes postgres to die


> pgsql-bugs@postgresql.org writes:
> > explain analyze causes postgres to die
>
> Can't do much with this, since you have not provided a complete test
> case.
>
> regards, tom lane
>
>

Re: Bug #883: explain analyze causes postgres to die

From
Tom Lane
Date:
"Chris Hodson" <nerf@slacker.com> writes:
> I included the code in the "example code" box.  I'll include it again here.
> If you need more info, just let me know.

I'm still not able to duplicate this.  Perhaps you could provide a stack
trace?  (Preferably from a backend built with --enable-debug.)

            regards, tom lane