8.2beta1 restarts given query

From: "Per Jensen" <per2jensen(at)gmail(dot)com>
To: pgsql-bugs(at)postgresql(dot)org
Subject: 8.2beta1 restarts given query
Date: 2006-10-11 06:16:32
Message-ID: 8ddb7c4f0610102316s11096faeucfcd7c634e55584@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Bughunters,

I am testing the 8.2beta1 server with a pg_dump/restore from a debian
production sarge-PG74 instance.

When the dump is restored to a test PG-8.1.3 my application works
nicely (have not upgraded the production server though).

When the same dump is restored to a PG-8.2beta1 some queries succeed
and others fail. The server *restarts* as can be seen from the server
logfile below.

The database is accessed through iBatis version 1.3.1 --> jakarta DBCP 1.2.1

OS: SuSe 8.0

JDBC driver used: postgresql-8.2dev-503.jdbc3.jar' downloaded from
'jdbc.postgresql.org'.

JVM: java full version "1.5.0-b64"

PG-8.2beta1 built from source with this configure command:
'$ ./configure --prefix=/srv/pg-8.2.0.beta1 --with-zlib' (from config.log)

Version from version():
------------------------------
Welcome to psql 8.2beta1, the PostgreSQL interactive terminal.

Type: \copyright for distribution terms
\h for help with SQL commands
\? for help with psql commands
\g or terminate with semicolon to execute query
\q to quit

XXXX=> select version();
LOG: statement: BEGIN
LOG: statement: select version();
version
-------------------------------------------------------------------------
PostgreSQL 8.2beta1 on i686-pc-linux-gnu, compiled by GCC gcc (GCC) 3.2
(1 row)

Locales:
-----------
Locale used in initdb command: LATIN1
Locale used in createdb command: LATIN1
Locale used in production db: LATIN1

Table description:
-----------------------
Table "booking.booking"
Column | Type |
Modifiers
--------------------+--------------------------+-------------------------------------------------------------------
id | integer | not null default
nextval(('booking.booking_seq'::text)::regclass)
customer_id | integer | not null
type | integer | not null
fromtime | timestamp with time zone | not null
totime | timestamp with time zone | not null
contact | character varying(255) |
comment | character varying(2000) |
driver | character varying(255) |
last_updated | timestamp with time zone | not null
sms_last_sent | timestamp with time zone |
location | character varying(255) |
sms_sent | boolean | not null
deleted | boolean | not null
regular | boolean | not null
express_booking_id | integer |
Indexes:
"booking_pkey" PRIMARY KEY, btree (id)
"booking_customer_id_idx" btree (customer_id)
"booking_express_booking_id_idx" btree (express_booking_id)
"booking_fromtime_idx" btree (fromtime)
"booking_totime_idx" btree (totime)
Foreign-key constraints:
"fk_booking_customer_id" FOREIGN KEY (customer_id) REFERENCES customer(id)
"fk_booking_pickup_type" FOREIGN KEY ("type") REFERENCES enum_value(id)
Triggers:
tr_after_update AFTER UPDATE ON booking.booking FOR EACH ROW
EXECUTE PROCEDURE tr_maintain_pickup_status()

Query as logged on client:
---------------------------------
DEBUG 2006-10-10 13:31:56,481 PreparedStatement - {pstm-101012}
PreparedStatement: select distinct id, customer_id,
express_booking_id, type, fromtime, totime, contact, comment, driver,
sms_sent, regular, deleted, last_updated, sms_last_sent, location
from ( select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location from booking.booking, public.customer
WHERE booking.booking.customer_id = public.customer.id
AND fromtime >= ? AND totime
<= ? AND customer.zip < '5000'
UNION select public.customer.name,
booking.booking.id as id, customer_id, express_booking_id, type,
fromtime, totime, contact, comment, driver, sms_sent, regular,
deleted, last_updated, sms_last_sent, location from
booking.booking, public.customer WHERE
booking.booking.customer_id = public.customer.id AND
fromtime >= ? AND totime <= ?
AND customer.zip >= '5000'
) as subselect
DEBUG 2006-10-10 13:31:56,481 PreparedStatement - {pstm-101012}
Parameters: [2006-10-10 00:00:00.0, 2006-10-10 23:59:59.0, 2006-10-10
00:00:00.0, 2006-10-10 23:59:59.0]
DEBUG 2006-10-10 13:31:56,482 PreparedStatement - {pstm-101012}
Types: [java.sql.Timestamp, java.sql.Timestamp, java.sql.Timestamp,
java.sql.Timestamp]

Query as logged on server:
-----------------------------------
This log snip is from the working 8.1.3 instance beacuse the 8.2beta1
does not log the query before crash.

<snip>
LOG: statement: PREPARE <unnamed> AS SET SESSION CHARACTERISTICS AS
TRANSACTION ISOLATION LEVEL SERIALIZABLE
LOG: statement: <BIND>
LOG: statement: EXECUTE <unnamed> [PREPARE: SET SESSION
CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL SERIALIZABLE]
LOG: statement: <BIND>
LOG: statement: EXECUTE <unnamed> [PREPARE: BEGIN]
LOG: statement: PREPARE <unnamed> AS
select distinct id, customer_id, express_booking_id,
type, fromtime, totime, contact, comment, driver, sms_sent, regular,
deleted, last_updated, sms_last_sent, location
from
(
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= $1
AND
totime <= $2
AND

customer.zip < '5000'

UNION
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= $3
AND
totime <= $4
AND

customer.zip >= '5000'

) as subselect

LOG: statement: <BIND>
LOG: statement: EXECUTE <unnamed> [PREPARE:
select distinct id, customer_id, express_booking_id,
type, fromtime, totime, contact, comment, driver, sms_sent, regular,
deleted, last_updated, sms_last_sent, location
from
(
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= $1
AND
totime <= $2
AND

customer.zip < '5000'

UNION
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= $3
AND
totime <= $4
AND

customer.zip >= '5000'

) as subselect
]
LOG: statement: <BIND>
LOG: statement: EXECUTE <unnamed> [PREPARE: ROLLBACK]

</snip>

It seems the querys is sent twice, must look into that later.

Same query in psql:
--------------------------
The query is successfull in psql and returns 63 rows

select distinct id, customer_id, express_booking_id, type,
fromtime, totime, contact, comment, driver, sms_sent, regular,
deleted, last_updated, sms_last_sent, location
from
(
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= '2006-10-10 00:00:00'
AND
totime <= '2006-10-10 23:59:59'
AND

customer.zip < '5000'

UNION
select public.customer.name, booking.booking.id as id,
customer_id, express_booking_id, type, fromtime, totime, contact,
comment, driver, sms_sent, regular, deleted, last_updated,
sms_last_sent, location
from booking.booking, public.customer
WHERE
booking.booking.customer_id = public.customer.id
AND
fromtime >= '2006-10-10 00:00:00'
AND
totime <= '2006-10-10 23:59:59'
AND

customer.zip >= '5000'
) as subselect

The error in the client log is:
--------------------------------------
Caused by: java.io.EOFException
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:258)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1164)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:190)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:354)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:258)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.ibatis.db.jdbc.logging.PreparedStatementLogProxy.invoke(Unknown
Source)
at $Proxy1.executeQuery(Unknown Source)
... 56 more

The error in server log is:
--------------------------------
LOG: execute <unnamed>: SET SESSION CHARACTERISTICS AS TRANSACTION
ISOLATION LEVEL SERIALIZABLE
LOG: execute S_1: BEGIN
LOG: server process (PID 23573) was terminated by signal 11
LOG: terminating any other active server processes
WARNING: terminating connection because of crash of another server process
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.
HINT: In a moment you should be able to reconnect to the database
and repeat your command.
LOG: all server processes terminated; reinitializing
LOG: database system was interrupted at 2006-10-10 13:42:34 CEST
LOG: checkpoint record is at 0/5240B8CC
LOG: redo record is at 0/5240B8CC; undo record is at 0/0; shutdown TRUE
LOG: next transaction ID: 0/143146; next OID: 6644019
LOG: next MultiXactId: 1; next MultiXactOffset: 0
LOG: database system was not properly shut down; automatic recovery
in progress
LOG: connection received: host=::ffff:127.0.0.1 port=33904
FATAL: the database system is starting up
LOG: redo starts at 0/5240B914
LOG: record with zero length at 0/5240F9FC
LOG: redo done at 0/5240F9D4
LOG: database system is ready
LOG: transaction ID wrap limit is 2147484172, limited by database "postgres"

The 8.2beta1 server does not log the query before it crashes

Feel free to ask more information if this bugreport is useful to you.

Thank you for a great database !

Regards
Per Jensen

--
--
Dårlige volt er noget skidt !

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Per Jensen 2006-10-11 07:12:50 BUG #2686: 8.2beta1 restarts given query
Previous Message Quinn Weaver 2006-10-11 00:42:24 Minor doc bug in 8.1.4