8.2beta1 restarts given query - Mailing list pgsql-bugs

From Per Jensen
Subject 8.2beta1 restarts given query
Date
Msg-id 8ddb7c4f0610102316s11096faeucfcd7c634e55584@mail.gmail.com
Whole thread Raw
Responses Re: 8.2beta1 restarts given query
List 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=3D/srv/pg-8.2.0.beta1 --with-zlib' (from config.lo=
g)

 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=3D> 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 =3D public.customer.id
AND               fromtime >=3D ?             AND               totime
<=3D ?             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 =3D public.customer.id         AND
    fromtime >=3D ?             AND               totime <=3D ?
 AND                     customer.zip >=3D '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 =3D public.customer.id
                 AND
                    fromtime >=3D $1
                  AND
                    totime <=3D $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 =3D public.customer.id
                 AND
                    fromtime >=3D $3
                  AND
                    totime <=3D $4
                  AND

                           customer.zip >=3D '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 =3D public.customer.id
                 AND
                    fromtime >=3D $1
                  AND
                    totime <=3D $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 =3D public.customer.id
                 AND
                    fromtime >=3D $3
                  AND
                    totime <=3D $4
                  AND

                           customer.zip >=3D '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 =3D public.customer.id
                 AND
                    fromtime >=3D '2006-10-10 00:00:00'
                  AND
                    totime <=3D '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 =3D public.customer.id
                 AND
                    fromtime >=3D '2006-10-10 00:00:00'
                  AND
                    totime <=3D '2006-10-10 23:59:59'
                  AND

                           customer.zip >=3D '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(QueryEx=
ecutorImpl.java:1164)
         at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorI=
mpl.java:190)
         at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdb=
c2Statement.java:452)
         at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(Ab=
stractJdbc2Statement.java:354)
         at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(Abstra=
ctJdbc2Statement.java:258)
         at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuer=
y(DelegatingPreparedStatement.java:92)
         at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source)
         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMetho=
dAccessorImpl.java:25)
         at java.lang.reflect.Method.invoke(Method.java:585)
         at com.ibatis.db.jdbc.logging.PreparedStatementLogProxy.invoke(Unk=
nown
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=3D::ffff:127.0.0.1 port=3D33904
 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 "postgr=
es"

 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


--=20
--
D=E5rlige volt er noget skidt !

pgsql-bugs by date:

Previous
From: "Milen A. Radev"
Date:
Subject: Re: BUG #2684: Memory leak in libpq
Next
From: "Per Jensen"
Date:
Subject: BUG #2686: 8.2beta1 restarts given query