Re: BUG #5622: Query failed: server closed the connection unexpectedly

On Tue, Aug 17, 2010 at 5:26 PM, Thue Janus Kristensen <thuejk(at)gmail(dot)com> wrote:
>
> The following bug has been logged online:
>
> Bug reference:      5622
> Logged by:          Thue Janus Kristensen
> Email address:      thuejk(at)gmail(dot)com
> PostgreSQL version: 8.4.4
> Operating system:   Ubuntu 10.04 LTS i386
> Description:        Query failed: server closed the connection unexpectedly
> Details:
>
> I have a 100% reproducible server crash with postgresql. This crash does not
> happen on my 8.3 installation.
>
> When the crash occurs I get
>        pg_query(): Query failed: server closed the connection unexpectedly
>        This probably means the server terminated abnormally
>        before or while processing the request.
>
> However, I have been unable to simplify the error condition :(. I tried
> dumping 8000 lines of sql, but when I run them separately, I don't get a
> crash.
>
> The last lines before the crash are ($db->query is a prepared query,
> $db->simple_query is a non-prepared query):
> <?php
>    $db->query("SAVEPOINT lala");
>    $res = questions::move_question($t->e, $g1q1_id, $g2_id); //some queries
> here
>    $db->query("ROLLBACK TO SAVEPOINT lala");
>    $db->query("RELEASE SAVEPOINT lala");
>    //some queries here
>    $res = aas::insert_in_group($t->e, $aa_id, $g2_id);
>    $res = questions::move_question($t->e, $g1q1_id, $g2_id);
>    //crash when line below is run!
>    $db->simple_query("SET CONSTRAINTS ALL IMMEDIATE");
> ?>
>
> /var/log/syslog:
> Aug 17 23:08:26 thue-laptop kernel: [46188.626357] postgres[11461]: segfault
> at 21723858 ip 00772286 sp bf8a4a80 error 4 in postgres[621000+446000]
>
> /var/log/postgresql/postgresql-8.4-main.log
> 2010-08-17 23:08:26 CEST LOG:  server process (PID 11461) was terminated by
> signal 11: Segmentation fault
> 2010-08-17 23:08:26 CEST LOG:  terminating any other active server
> processes
> 2010-08-17 23:08:26 CEST WARNING:  terminating connection because of crash
> of another server process
> 2010-08-17 23:08:26 CEST DETAIL:  The postmaster has commanded this server
> process to roll back the current transaction and exit,\
>  because another server process exited abnormally and possibly corrupted
> shared memory.
> 2010-08-17 23:08:26 CEST HINT:  In a moment you should be able to reconnect
> to the database and repeat your command.
> 2010-08-17 23:08:26 CEST LOG:  all server processes terminated;
> reinitializing
> 2010-08-17 23:08:26 CEST LOG:  database system was interrupted; last known
> up at 2010-08-17 23:04:02 CEST
> 2010-08-17 23:08:26 CEST LOG:  database system was not properly shut down;
> automatic recovery in progress
> 2010-08-17 23:08:26 CEST LOG:  redo starts at 0/37500054
>
> I realize that this is probably not enough to understand the bug, but I will
> be happy to try to debug it further, if I am given a pointer as to how.

Well, obviously the best thing would be to isolate a reproducible test
case. But maybe a good start would be to try to get a list of the
exact series of SQL statements that are being executed. Perhaps you
could set log_min_duration_statement=0 and then find 'em in the logs.
If you do this with some trivial query in the places where you have
"some queries here", it doesn't crash.

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