Обсуждение: Possible bug / regression from generated keys

Summary:
I'm getting an exception from the ResultSet returned from
getGeneratedKey() from a batch insert PreparedStatement. When I use
any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions, but
when I use postgresql-9.1-902.jdbc4.jar it works.

Has anyone seen anything like this? How can I debug this problem
further? How should I go about determining if this is a bug?

Exception:
java.lang.ArrayIndexOutOfBoundsException: 4
    at org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
    at org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
    at org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
...

Usually followed later by this exception:
org.postgresql.util.PSQLException: Bad value for type long : ,
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
    at org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
    at org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
...

Setup:
OS: Ubuntu 10.04
PG: 9.2
JDBC: postgresql-9.2-1001.jdbc4.jar

I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.

I *believe* that it must have something to do with concurrent database
connections or connection reuse, but I haven't been successful at
creating a test case, despite trying for several days now.

Suggestions? I've got a mountain of data - if anyone needs more details.


--
Pete

Thanks dmp -

Ah! Forgot to include the column information -

I added code to the function call which is reading the ResultSet
object, and output the column name and type info, so the column is
declared:
position_id bigint default nextval('track_position_sequence'),

And according to JDBC says "bigserial position_id" which I believe is correct?





On Wed, Nov 7, 2012 at 11:44 AM, dmp <danap@ttc-cmc.net> wrote:
> I don't think a mountain of data is required for this one.
> The ByteConverter class does not exist for the 9.1-902 so
> was introduced later and is in 9.2-100X. Since git holds
> no history I can not determine introduction, but a search
> of this mailing list would perhaps lead to the reason for
> the change.
>
> What I can say is it looks like the column is binary. I
> could compile the source for 9.2-1001 with output that
> may tell you perhaps more information. I suspect though
> someone here is more familiar with the change to understand
> the problem. I would say this behavior is undesirable and
> could be classified as a bug.
>
> danap.
>
>
>
> Peter Cooner wrote:
>>
>> Summary:
>> I'm getting an exception from the ResultSet returned from
>> getGeneratedKey() from a batch insert PreparedStatement. When I use
>> any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions, but
>> when I use postgresql-9.1-902.jdbc4.jar it works.
>>
>> Has anyone seen anything like this? How can I debug this problem
>> further? How should I go about determining if this is a bug?
>>
>> Exception:
>> java.lang.ArrayIndexOutOfBoundsException: 4
>>         at org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>         at
>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>         at
>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>> ...
>>
>> Usually followed later by this exception:
>> org.postgresql.util.PSQLException: Bad value for type long : ,
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>         at
>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>         at
>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>         at
>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>> ...
>>
>> Setup:
>> OS: Ubuntu 10.04
>> PG: 9.2
>> JDBC: postgresql-9.2-1001.jdbc4.jar
>>
>> I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.
>>
>> I *believe* that it must have something to do with concurrent database
>> connections or connection reuse, but I haven't been successful at
>> creating a test case, despite trying for several days now.
>>
>> Suggestions? I've got a mountain of data - if anyone needs more details.
>
>



--
Pete
"Yates went on to say that using MS formats left a fresh, minty feeing
in user's mouths while every time an open [format] is used a kitten
dies." -- maggard (on slashdot)

perl -lne '(1x$_) !~ /^1?$|^(11+?)\1+$/ && print "$_ is prime"'

I don't think a mountain of data is required for this one.
The ByteConverter class does not exist for the 9.1-902 so
was introduced later and is in 9.2-100X. Since git holds
no history I can not determine introduction, but a search
of this mailing list would perhaps lead to the reason for
the change.

What I can say is it looks like the column is binary. I
could compile the source for 9.2-1001 with output that
may tell you perhaps more information. I suspect though
someone here is more familiar with the change to understand
the problem. I would say this behavior is undesirable and
could be classified as a bug.

danap.


Peter Cooner wrote:
 > Summary:
 > I'm getting an exception from the ResultSet returned from
 > getGeneratedKey() from a batch insert PreparedStatement. When I use
 > any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions, but
 > when I use postgresql-9.1-902.jdbc4.jar it works.
 >
 > Has anyone seen anything like this? How can I debug this problem
 > further? How should I go about determining if this is a bug?
 >
 > Exception:
 > java.lang.ArrayIndexOutOfBoundsException: 4
 >     at org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
 >     at
org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
 >     at
org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
 > ...
 >
 > Usually followed later by this exception:
 > org.postgresql.util.PSQLException: Bad value for type long : ,
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
 >     at
org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
 >     at
org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
 >     at
org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
 > ...
 >
 > Setup:
 > OS: Ubuntu 10.04
 > PG: 9.2
 > JDBC: postgresql-9.2-1001.jdbc4.jar
 >
 > I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.
 >
 > I *believe* that it must have something to do with concurrent database
 > connections or connection reuse, but I haven't been successful at
 > creating a test case, despite trying for several days now.
 >
 > Suggestions? I've got a mountain of data - if anyone needs more details.

Sorry i did not post the first reply to the mailing list, but did
now. I would say see wait and see if someone else replies or search
the list for change.

Of hand I would say Bigserial Type java.lang.Long int8 should not
have been caught by that routine. From the Field class that column
is being tied to Binary Data.

Field Class
//The V3 protocol defines two constants for the format of data
     public static final int TEXT_FORMAT = 0;
     public static final int BINARY_FORMAT = 1;

By the way the ByteConverter was created by:

Helper methods to parse java base types from byte arrays.
  *
  * @author Mikko Tiihonen

danap.

Peter Cooner wrote:
> Thanks dmp -
>
> Ah! Forgot to include the column information -
>
> I added code to the function call which is reading the ResultSet
> object, and output the column name and type info, so the column is
> declared:
> position_id bigint default nextval('track_position_sequence'),
>
> And according to JDBC says "bigserial position_id" which I believe is correct?
>
>
> On Wed, Nov 7, 2012 at 11:44 AM, dmp<danap@ttc-cmc.net>  wrote:
>> I don't think a mountain of data is required for this one.
>> The ByteConverter class does not exist for the 9.1-902 so
>> was introduced later and is in 9.2-100X. Since git holds
>> no history I can not determine introduction, but a search
>> of this mailing list would perhaps lead to the reason for
>> the change.
>>
>> What I can say is it looks like the column is binary. I
>> could compile the source for 9.2-1001 with output that
>> may tell you perhaps more information. I suspect though
>> someone here is more familiar with the change to understand
>> the problem. I would say this behavior is undesirable and
>> could be classified as a bug.
>>
>> danap.
>>
>>
>>
>> Peter Cooner wrote:
>>>
>>> Summary:
>>> I'm getting an exception from the ResultSet returned from
>>> getGeneratedKey() from a batch insert PreparedStatement. When I use
>>> any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions, but
>>> when I use postgresql-9.1-902.jdbc4.jar it works.
>>>
>>> Has anyone seen anything like this? How can I debug this problem
>>> further? How should I go about determining if this is a bug?
>>>
>>> Exception:
>>> java.lang.ArrayIndexOutOfBoundsException: 4
>>>          at org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>>          at
>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>>          at
>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>>> ...
>>>
>>> Usually followed later by this exception:
>>> org.postgresql.util.PSQLException: Bad value for type long : ,
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>>          at
>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>>          at
>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>>          at
>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>>> ...
>>>
>>> Setup:
>>> OS: Ubuntu 10.04
>>> PG: 9.2
>>> JDBC: postgresql-9.2-1001.jdbc4.jar
>>>
>>> I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.
>>>
>>> I *believe* that it must have something to do with concurrent database
>>> connections or connection reuse, but I haven't been successful at
>>> creating a test case, despite trying for several days now.
>>>
>>> Suggestions? I've got a mountain of data - if anyone needs more details.
>>
>>
>
>
>

I can replicate the problem within our code at will, but I've been
unable to produce a standalone test case despite my best efforts.

I started building this test case by using just the postgresql jar,
then tried adding postgis jar, but have yet to get around to trying to
writing one that uses DBCP or DbUtils.

it always seems to happen on the same column, and it doesn't seem to
ever happen on the first row off the batch insert, but that could be
just by chance.




On Wed, Nov 7, 2012 at 4:33 PM, Dave Cramer <pg@fastcrypt.com> wrote:
> Peter,
>
> Is this easily replicated, or does it only happen once in a while ?
>
> Dave
>
> Dave Cramer
>
> dave.cramer(at)credativ(dot)ca
> http://www.credativ.ca
>
>
>
> On Wed, Nov 7, 2012 at 12:21 PM, dmp <danap@ttc-cmc.net> wrote:
>>
>> Sorry i did not post the first reply to the mailing list, but did
>> now. I would say see wait and see if someone else replies or search
>> the list for change.
>>
>> Of hand I would say Bigserial Type java.lang.Long int8 should not
>> have been caught by that routine. From the Field class that column
>> is being tied to Binary Data.
>>
>> Field Class
>> //The V3 protocol defines two constants for the format of data
>>     public static final int TEXT_FORMAT = 0;
>>     public static final int BINARY_FORMAT = 1;
>>
>> By the way the ByteConverter was created by:
>>
>> Helper methods to parse java base types from byte arrays.
>>  *
>>  * @author Mikko Tiihonen
>>
>> danap.
>>
>>
>> Peter Cooner wrote:
>>>
>>> Thanks dmp -
>>>
>>> Ah! Forgot to include the column information -
>>>
>>> I added code to the function call which is reading the ResultSet
>>> object, and output the column name and type info, so the column is
>>> declared:
>>> position_id bigint default nextval('track_position_sequence'),
>>>
>>> And according to JDBC says "bigserial position_id" which I believe is
>>> correct?
>>>
>>>
>>> On Wed, Nov 7, 2012 at 11:44 AM, dmp<danap@ttc-cmc.net>  wrote:
>>>>
>>>> I don't think a mountain of data is required for this one.
>>>> The ByteConverter class does not exist for the 9.1-902 so
>>>> was introduced later and is in 9.2-100X. Since git holds
>>>> no history I can not determine introduction, but a search
>>>> of this mailing list would perhaps lead to the reason for
>>>> the change.
>>>>
>>>> What I can say is it looks like the column is binary. I
>>>> could compile the source for 9.2-1001 with output that
>>>> may tell you perhaps more information. I suspect though
>>>> someone here is more familiar with the change to understand
>>>> the problem. I would say this behavior is undesirable and
>>>> could be classified as a bug.
>>>>
>>>> danap.
>>>>
>>>>
>>>>
>>>> Peter Cooner wrote:
>>>>>
>>>>>
>>>>> Summary:
>>>>> I'm getting an exception from the ResultSet returned from
>>>>> getGeneratedKey() from a batch insert PreparedStatement. When I use
>>>>> any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions, but
>>>>> when I use postgresql-9.1-902.jdbc4.jar it works.
>>>>>
>>>>> Has anyone seen anything like this? How can I debug this problem
>>>>> further? How should I go about determining if this is a bug?
>>>>>
>>>>> Exception:
>>>>> java.lang.ArrayIndexOutOfBoundsException: 4
>>>>>          at
>>>>> org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>>>>> ...
>>>>>
>>>>> Usually followed later by this exception:
>>>>> org.postgresql.util.PSQLException: Bad value for type long : ,
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>>>>>          at
>>>>>
>>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>>>>> ...
>>>>>
>>>>> Setup:
>>>>> OS: Ubuntu 10.04
>>>>> PG: 9.2
>>>>> JDBC: postgresql-9.2-1001.jdbc4.jar
>>>>>
>>>>> I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.
>>>>>
>>>>> I *believe* that it must have something to do with concurrent database
>>>>> connections or connection reuse, but I haven't been successful at
>>>>> creating a test case, despite trying for several days now.
>>>>>
>>>>> Suggestions? I've got a mountain of data - if anyone needs more
>>>>> details.
>>>>
>>>>
>>>>
>>>
>>>
>>>
>>
>>
>>
>> --
>> Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
>> To make changes to your subscription:
>> http://www.postgresql.org/mailpref/pgsql-jdbc
>
>



--
Pete
"Yates went on to say that using MS formats left a fresh, minty feeing
in user's mouths while every time an open [format] is used a kitten
dies." -- maggard (on slashdot)

perl -lne '(1x$_) !~ /^1?$|^(11+?)\1+$/ && print "$_ is prime"'

Yeah, though changing the JDBC driver is the lone modification
required to cause the problem.

I'll try switching around some of the code which should remove DBCP
from the system leaving only DbUtils. it will take a little more work
to pull DbUtils though.



On Wed, Nov 7, 2012 at 6:07 PM, Dave Cramer <pg@fastcrypt.com> wrote:
> Peter,
>
> I was afraid of that. So there are a few utilities between you and the
> driver.
>
> Dave
>
> Dave Cramer
>
> dave.cramer(at)credativ(dot)ca
> http://www.credativ.ca
>
>
>
> On Wed, Nov 7, 2012 at 6:00 PM, Peter Cooner <petriborg@gmail.com> wrote:
>>
>> I can replicate the problem within our code at will, but I've been
>> unable to produce a standalone test case despite my best efforts.
>>
>> I started building this test case by using just the postgresql jar,
>> then tried adding postgis jar, but have yet to get around to trying to
>> writing one that uses DBCP or DbUtils.
>>
>> it always seems to happen on the same column, and it doesn't seem to
>> ever happen on the first row off the batch insert, but that could be
>> just by chance.
>>
>>
>>
>>
>> On Wed, Nov 7, 2012 at 4:33 PM, Dave Cramer <pg@fastcrypt.com> wrote:
>> > Peter,
>> >
>> > Is this easily replicated, or does it only happen once in a while ?
>> >
>> > Dave
>> >
>> > Dave Cramer
>> >
>> > dave.cramer(at)credativ(dot)ca
>> > http://www.credativ.ca
>> >
>> >
>> >
>> > On Wed, Nov 7, 2012 at 12:21 PM, dmp <danap@ttc-cmc.net> wrote:
>> >>
>> >> Sorry i did not post the first reply to the mailing list, but did
>> >> now. I would say see wait and see if someone else replies or search
>> >> the list for change.
>> >>
>> >> Of hand I would say Bigserial Type java.lang.Long int8 should not
>> >> have been caught by that routine. From the Field class that column
>> >> is being tied to Binary Data.
>> >>
>> >> Field Class
>> >> //The V3 protocol defines two constants for the format of data
>> >>     public static final int TEXT_FORMAT = 0;
>> >>     public static final int BINARY_FORMAT = 1;
>> >>
>> >> By the way the ByteConverter was created by:
>> >>
>> >> Helper methods to parse java base types from byte arrays.
>> >>  *
>> >>  * @author Mikko Tiihonen
>> >>
>> >> danap.
>> >>
>> >>
>> >> Peter Cooner wrote:
>> >>>
>> >>> Thanks dmp -
>> >>>
>> >>> Ah! Forgot to include the column information -
>> >>>
>> >>> I added code to the function call which is reading the ResultSet
>> >>> object, and output the column name and type info, so the column is
>> >>> declared:
>> >>> position_id bigint default nextval('track_position_sequence'),
>> >>>
>> >>> And according to JDBC says "bigserial position_id" which I believe is
>> >>> correct?
>> >>>
>> >>>
>> >>> On Wed, Nov 7, 2012 at 11:44 AM, dmp<danap@ttc-cmc.net>  wrote:
>> >>>>
>> >>>> I don't think a mountain of data is required for this one.
>> >>>> The ByteConverter class does not exist for the 9.1-902 so
>> >>>> was introduced later and is in 9.2-100X. Since git holds
>> >>>> no history I can not determine introduction, but a search
>> >>>> of this mailing list would perhaps lead to the reason for
>> >>>> the change.
>> >>>>
>> >>>> What I can say is it looks like the column is binary. I
>> >>>> could compile the source for 9.2-1001 with output that
>> >>>> may tell you perhaps more information. I suspect though
>> >>>> someone here is more familiar with the change to understand
>> >>>> the problem. I would say this behavior is undesirable and
>> >>>> could be classified as a bug.
>> >>>>
>> >>>> danap.
>> >>>>
>> >>>>
>> >>>>
>> >>>> Peter Cooner wrote:
>> >>>>>
>> >>>>>
>> >>>>> Summary:
>> >>>>> I'm getting an exception from the ResultSet returned from
>> >>>>> getGeneratedKey() from a batch insert PreparedStatement. When I use
>> >>>>> any of the postgresql-9.2-100X.jdbc4.jar drivers I get exceptions,
>> >>>>> but
>> >>>>> when I use postgresql-9.1-902.jdbc4.jar it works.
>> >>>>>
>> >>>>> Has anyone seen anything like this? How can I debug this problem
>> >>>>> further? How should I go about determining if this is a bug?
>> >>>>>
>> >>>>> Exception:
>> >>>>> java.lang.ArrayIndexOutOfBoundsException: 4
>> >>>>>          at
>> >>>>> org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>> >>>>> ...
>> >>>>>
>> >>>>> Usually followed later by this exception:
>> >>>>> org.postgresql.util.PSQLException: Bad value for type long : ,
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.toLong(AbstractJdbc2ResultSet.java:2971)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2163)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
>> >>>>>          at
>> >>>>>
>> >>>>>
>> >>>>> org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
>> >>>>> ...
>> >>>>>
>> >>>>> Setup:
>> >>>>> OS: Ubuntu 10.04
>> >>>>> PG: 9.2
>> >>>>> JDBC: postgresql-9.2-1001.jdbc4.jar
>> >>>>>
>> >>>>> I'm also using PostGIS 2.0.1 jar, Apache Commons DBUtils, and DBCP.
>> >>>>>
>> >>>>> I *believe* that it must have something to do with concurrent
>> >>>>> database
>> >>>>> connections or connection reuse, but I haven't been successful at
>> >>>>> creating a test case, despite trying for several days now.
>> >>>>>
>> >>>>> Suggestions? I've got a mountain of data - if anyone needs more
>> >>>>> details.
>> >>>>
>> >>>>
>> >>>>
>> >>>
>> >>>
>> >>>
>> >>
>> >>
>> >>
>> >> --
>> >> Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
>> >> To make changes to your subscription:
>> >> http://www.postgresql.org/mailpref/pgsql-jdbc
>> >
>> >
>>
>>
>>
>> --
>> Pete
>> "Yates went on to say that using MS formats left a fresh, minty feeing
>> in user's mouths while every time an open [format] is used a kitten
>> dies." -- maggard (on slashdot)
>>
>> perl -lne '(1x$_) !~ /^1?$|^(11+?)\1+$/ && print "$_ is prime"'
>>
>>
>> --
>> Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
>> To make changes to your subscription:
>> http://www.postgresql.org/mailpref/pgsql-jdbc
>
>



--
Pete
"Yates went on to say that using MS formats left a fresh, minty feeing
in user's mouths while every time an open [format] is used a kitten
dies." -- maggard (on slashdot)

perl -lne '(1x$_) !~ /^1?$|^(11+?)\1+$/ && print "$_ is prime"'

I can try as indicated to rebuild the jar so that Peter could have an output
of the exact value that is throwing the error when it occurs. To limit output
I would then recommend a case that would throw the error soon with as little
data processing as possible. Let me know if this maybe something I could do
to help.

danap.

Dave Cramer wrote:
> Well there is a relatively easy fix that would get rid of the problem.
> Currently we don't check the length of the array that we are trying to
> convert. However I'd like to understand how the problem is manifest
> before doing that.
>
> Dave
>
> Dave Cramer
>
> dave.cramer(at)credativ(dot)ca
> http://www.credativ.ca

OK, I've spent some time and removed the DBCP from the mix - I'm now
using SimpleDataSource object - the error persists. I'll work this
next at removing the use of DbUtil for the specific query.

Its rather odd.

position_id inserts that worked:
1075 through 1083

But 1084 fails - the id is in the database, but the result fails to return.

I looked at the ids, and they are continuous in the database, so the
inserts are working...

The next value to come back successfully from the batch is 1088.

I'm going to add a batch counter to my outputs... I'll get back to you
on this trail.



On Wed, Nov 7, 2012 at 8:04 PM, dmp <danap@ttc-cmc.net> wrote:
> I can try as indicated to rebuild the jar so that Peter could have an output
> of the exact value that is throwing the error when it occurs. To limit
> output
> I would then recommend a case that would throw the error soon with as little
> data processing as possible. Let me know if this maybe something I could do
> to help.
>
> danap.
>
>
> Dave Cramer wrote:
>>
>> Well there is a relatively easy fix that would get rid of the problem.
>> Currently we don't check the length of the array that we are trying to
>> convert. However I'd like to understand how the problem is manifest
>> before doing that.
>>
>> Dave
>>
>> Dave Cramer
>>
>> dave.cramer(at)credativ(dot)ca
>> http://www.credativ.ca



--
Pete
"Yates went on to say that using MS formats left a fresh, minty feeing
in user's mouths while every time an open [format] is used a kitten
dies." -- maggard (on slashdot)

perl -lne '(1x$_) !~ /^1?$|^(11+?)\1+$/ && print "$_ is prime"'

OK, so here is the batch info:

batch number, number of rows
1, 2
2, 3
3, 4
4, 4 - failed on row 4 - PSQLException: Bad value for type long :
5, 3 - failed on row 3 - PSQLException: Bad value for type long :
6, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
7, 4
8, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
9, 2
10, 3
11, 4
12, 3 - failed on row 3 - PSQLException: Bad value for type long : =
13, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
14, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
15, 4 - failed on row 4 - PSQLException: Bad value for type long : M
16, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4

Always on column 1, position_id


Normally I would expect the batches to be larger, but I've reduced the
data speed for testing.

Ater some thought I'm in agreement with Dave. The backend must be sending
an unexpected value that can not be converted.

Peter can you please send a post of the core prepare commit code that is
used to create these batches along with the exact place in your code
before the PSQLExceptions codes are given. I assume from your original post
that would include the getGeneratedKeys() that you indicated is the place
the error occurs for the ResultSet?

A simple test code case to recreate the error would be of course best.

danap.

Peter Cooner wrote:
> OK, so here is the batch info:
>
> batch number, number of rows
> 1, 2
> 2, 3
> 3, 4
> 4, 4 - failed on row 4 - PSQLException: Bad value for type long :
> 5, 3 - failed on row 3 - PSQLException: Bad value for type long :
> 6, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
> 7, 4
> 8, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
> 9, 2
> 10, 3
> 11, 4
> 12, 3 - failed on row 3 - PSQLException: Bad value for type long : =
> 13, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
> 14, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
> 15, 4 - failed on row 4 - PSQLException: Bad value for type long : M
> 16, 1 - failed on row 1 - ArrayIndexOutOfBoundsException: 4
>
> Always on column 1, position_id
>
>
> Normally I would expect the batches to be larger, but I've reduced the
> data speed for testing.
>
 >
 >
> Dave Cramer wrote:
>> So I had a quick look at the code and the only way it gets into this
>> code is through a test which is essentially
>>
>> if ( isBinary and isINT8 )
>>
>> So unless the backend is sending an int8 as less than 8 bytes or there
>> is some other bug in the JDBC code in which it gets confused as to what
>> it is pointing to I don't see how it gets to this exception.
>>
>> Dave

I tried to write a test case for a few days before I mailed the list
and was unable to produce the problem :(

The following code pulls its connection from a SimpleDataSource()
object. Its a mess because I ripped all code that used DbUtils and
DBCP in the critical path. Despite the code being ripped up, it still
works and produces the problem when the 1001 driver is used.



        public List<Long> batchPos(int batchNumber, String sql,
Object[]... params) throws SQLException {
            Check.notNull("sql", sql);
            Check.notNull("params", params);

            Connection conn = null;
            PreparedStatement stmt = null;
            ResultSet rs = null;
            List<Long> result = null;
            Object[] row = null;

            try {
                conn = ds.getConnection();
                stmt = conn.prepareStatement(sql,
                        Statement.RETURN_GENERATED_KEYS);
                ParameterMetaData pmd = stmt.getParameterMetaData();

                for (int p = 0; p < params.length; p++) {
                    row = params[p];

                    if (pmd.getParameterCount() != row.length) {
                        throw new SQLException("Bad param length");
                    }

                    for (int r = 0; r < row.length; r++) {
                        if (row[r] != null) {
                            stmt.setObject(r + 1, row[r]);
                        } else {
                            stmt.setNull(r + 1, pmd.getParameterType(r + 1));
                        }
                    }

                    //this.fillStatement(stmt, row);
                    stmt.addBatch();
                }
                stmt.executeBatch();

                rs = stmt.getGeneratedKeys();
                result = new LinkedList<Long>();

                while (rs.next()) {

                    ResultSetMetaData meta = rs.getMetaData();
                    for (int i=1; i<=meta.getColumnCount(); i++) {
                        log.debug("[%d][%d] %s %s",
                                batchNumber,
                                i,
                                meta.getColumnTypeName(i),
                                meta.getColumnName(i)
                                );
                        Object obj = rs.getObject(i);
                        log.debug("[%d][%d] Object %s (%s)",
                                batchNumber,
                                i,
                                obj,
                                (obj!=null ?
obj.getClass().getSimpleName() : "null")
                                );
                    }

                    String column = meta.getColumnName(1);
                    if (!column.equals("position_id")) {
                        log.warn("Column 1 is not id, is %s", column);
                    }

                    result.add(rs.getLong(1));
                }

            } catch (Exception e) {
                log.error(e, "Batch %d general failure!", batchNumber);
                this.rethrow(new SQLException(e), sql, row);

            } finally {
                DbUtils.closeQuietly(conn, stmt, rs);
            }

            return result;
        }

2012-Nov-08 12:48:01 tdbd: ERROR (DbData.batchPos:533) Batch 3 general failure!
java.lang.ArrayIndexOutOfBoundsException: 4
    at org.postgresql.util.ByteConverter.int8(ByteConverter.java:29)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getLong(AbstractJdbc2ResultSet.java:2150)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:142)
    at org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:36)
    at org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:296)
    at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2703)
    at com.heheh.service.database.DbData$BatchRunner.batchPos(DbData.java:515)






On Thu, Nov 8, 2012 at 10:57 AM, dmp <danap@ttc-cmc.net> wrote:
> Ater some thought I'm in agreement with Dave. The backend must be sending
> an unexpected value that can not be converted.
>
> Peter can you please send a post of the core prepare commit code that is
> used to create these batches along with the exact place in your code
> before the PSQLExceptions codes are given. I assume from your original post
> that would include the getGeneratedKeys() that you indicated is the place
> the error occurs for the ResultSet?
>
> A simple test code case to recreate the error would be of course best.
>
> danap.
>

Bleh, sorry, forgot to mention, the exception line:

Object obj = rs.getObject(i);



On Thu, Nov 8, 2012 at 10:57 AM, dmp <danap@ttc-cmc.net> wrote:
> Ater some thought I'm in agreement with Dave. The backend must be sending
> an unexpected value that can not be converted.
>
> Peter can you please send a post of the core prepare commit code that is
> used to create these batches along with the exact place in your code
> before the PSQLExceptions codes are given. I assume from your original post
> that would include the getGeneratedKeys() that you indicated is the place
> the error occurs for the ResultSet?
>
> A simple test code case to recreate the error would be of course best.
>
> danap.
>
>

On Thu, 8 Nov 2012, Peter Cooner wrote:

> I tried to write a test case for a few days before I mailed the list
> and was unable to produce the problem :(

Based on this description, I created a self contained test which is
attached.

The problem is that the driver is splicing together a single
generated keys ResultSet from each individual batch execution, but
some results come back in text format and some come back in binary.
 The combined result has a single per column format flag and it gets
confused when trying to parse a text result that it thinks is in binary
format.

The driver needs to be taught not to change the requested format mid batch
execution, but this is a tricky area.

Kris Jurka

Brilliant! I wonder why my test case doesn't do that, as its so close
to yours, alas.

I'm glad the problem has finally been exposed. Any idea why this
doesn't happen in the older driver? Did something change or is by
chance?



On Thu, Nov 8, 2012 at 1:45 PM, Kris Jurka <books@ejurka.com> wrote:
>
>
> On Thu, 8 Nov 2012, Peter Cooner wrote:
>
>> I tried to write a test case for a few days before I mailed the list
>> and was unable to produce the problem :(
>
> Based on this description, I created a self contained test which is
> attached.
>
> The problem is that the driver is splicing together a single
> generated keys ResultSet from each individual batch execution, but
> some results come back in text format and some come back in binary.
>  The combined result has a single per column format flag and it gets
> confused when trying to parse a text result that it thinks is in binary
> format.
>
> The driver needs to be taught not to change the requested format mid batch
> execution, but this is a tricky area.
>
> Kris Jurka

On Thu, 8 Nov 2012, Peter Cooner wrote:

> Brilliant! I wonder why my test case doesn't do that, as its so close
> to yours, alas.

The key to reproducing this is having both a getParameterMetaData call
before execution and a batch size larger than the driver's
prepareThreshold, so if you tested a batch of two, this will never be
triggered.

> I'm glad the problem has finally been exposed. Any idea why this
> doesn't happen in the older driver? Did something change or is by
> chance?
>

The older driver's do not support binary transfer at all.

Kris Jurka

The other day I noticed the last few source files for pgjdbc available on
the website uncompress all the contents into the current directory rather
than into one source directory.

I updated the pgjdbc-build.sh script to handle not only building the various
JDK version Jar files, but also now creating the compressed tar source.
This can be done by specifying the argument switch -s.

If anyone is interested in this script please let know.

danap.