Mailing List webobjects-dev@wocommunity.org Message #306
From: Ralf Schuchardt <webobjects-dev@wocommunity.org>
Subject: Re: [WO-DEV] Postgresql jdbc driver upgrade not recommended
Date: Sat, 30 Oct 2021 19:26:17 +0200
To: WebObjects & WOnder Development <webobjects-dev@wocommunity.org>
There is a new driver version 42.3.1 fixing https://github.com/pgjdbc/pgjdbc/issues/2326, what looks like it is this issue.


On 30 Oct 2021, at 4:14, D Tim Cummings wrote:

> I can reproduce the error in just a few lines of code. Is anyone else using Postgresql JDBC driver 42.3.0?
>
>     public void doRepeatSave() {
>       EOEditingContext ec = ERXEC.newEditingContext();
>       // fetch the first record from database table tbl_person
>       TblPerson p = TblPerson.fetchTblPerson(ec, null);
>       BigDecimal bd150k = BigDecimal.valueOf(1500000000, 4);
>       for (int i=0; i < 10; i++) {
>         p.setDollarAmount(bd150k);
>         ec.saveChanges();
>         logger.info("Count " + i + " p.dollarAmount=" + p.dollarAmount() );
>       }
>     }
>
> After the sixth save (i=5) the value gets truncated.The first five times, saveChanges() doesn't even trigger an SQL "update" event.
>
>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0" withBindings: >
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 0 p.dollarAmount=150000.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 1 p.dollarAmount=150000.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 2 p.dollarAmount=150000.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 3 p.dollarAmount=150000.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 4 p.dollarAmount=150000.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 5 p.dollarAmount=15.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "UPDATE tbl_person SET dollar_amount = ?::numeric(38,4) WHERE id_person = ?::int4" withBindings: 1:150000.0000(dollarAmount), 2:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 6 p.dollarAmount=15.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "UPDATE tbl_person SET dollar_amount = ?::numeric(38,4) WHERE id_person = ?::int4" withBindings: 1:150000.0000(dollarAmount), 2:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 7 p.dollarAmount=15.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "UPDATE tbl_person SET dollar_amount = ?::numeric(38,4) WHERE id_person = ?::int4" withBindings: 1:150000.0000(dollarAmount), 2:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 8 p.dollarAmount=15.0000
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "UPDATE tbl_person SET dollar_amount = ?::numeric(38,4) WHERE id_person = ?::int4" withBindings: 1:150000.0000(dollarAmount), 2:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Begin Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - evaluateExpression: <com.webobjects.jdbcadaptor.PostgresqlExpression: "SELECT t0.dollar_amount, t0.id_person FROM tbl_person t0 WHERE t0.id_person = ?::int4" withBindings: 1:1(idPerson)>
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  - 1 row(s) processed
> Oct. 30 12:04:07 wopg4230[56385] DEBUG NSLog  -  === Commit Internal Transaction
> Oct. 30 12:04:07 wopg4230[56385] INFO com.triptera.demo.wopg4230.components.Main  - Count 9 p.dollarAmount=15.0000
>
> On 29/10/21 20:00, D Tim Cummings wrote:
>> I have built a small app which demonstrates this behaviour.
>>
>> https://github.com/timcu/wopg4230
>>
>> It is a very simple app with a database with one table with one record with one field (other than the primary key). The app has one WOComponent with one form with one text field and one save button.
>>
>> It is a maven app but that makes it easy to swap between jdbc driver versions.
>>
>> I would be interested if other people see the same behaviour. You will need to set up a postgresql database but I have put instructions on the github README.md on how to do that.
>>
>> Tim
>>
>> On 27/10/21 20:06, D Tim Cummings wrote:
>>> Postgresql data type : Numeric(38,4) allows null
>>>
>>> Java data type: BigDecimal
>>>
>>> EOModel using prototype: currencyAmount
>>>
>>> When number is first retrieved from database it has precision 10 scale 4 eg 150000.0000
>>>
>>> I click the edit button which puts the number in a textfield which has numberformat "$#,##0; ($#,##0)" and it displays as $150,000
>>>
>>> I click save button. Number in EO is now 150000 with precision 6 and scale 0
>>>
>>> I run ec().saveChanges() where ec() is my editingContext.
>>>
>>> Number in EO is still 150000 with precision 6 and scale 0
>>>
>>> I repeat the procedure "edit / save" several times and randomly the number in EO eventually becomes 15 with precision 2 and scale 0. If it happens before the saveChanges() then the new number gets saved to the database. However it can happen after the save in which case my app sees the small number but it doesn't get saved to database if I shutdown the app at that point and start it up again.
>>>
>>> It looks like a problem with my app except that it only started happening with the new JDBC driver and reverting the JDBC driver removes the problem.
>>>
>>>
>>> Tim
>>>
>>>
>>> On 27/10/21 18:48, Hugi Thordarson wrote:
>>>> Hi Tim,
>>>> out of curiosity, what's the data type of the number that's getting truncated? (both the DB and java/model side)
>>>>
>>>> - hugi
>>>>
>>>>
>>>>> On 27 Oct 2021, at 04:53, D Tim Cummings <webobjects-dev@wocommunity.org> wrote:
>>>>>
>>>>> I just upgraded my postgresql jdbc driver from 42.2.23 to 42.3.0 and suddenly any number returned from the database that ended in four zeros was having the zeros trimmed.
>>>>>
>>>>> For example
>>>>>
>>>>> 150000 became 15
>>>>>
>>>>> This did not affect numbers ending in three zeros
>>>>>
>>>>> 151000 stayed as 151000
>>>>>
>>>>> I am still looking for the cause but rolling back to 42.2.23 fixed the problem. Problem was reproducible on Postgresql 10.18 on Ubuntu and Postgresql 13.3 on Mac.
>>>>>
>>>>> I am using Wonder 7.2 with Postgresql plugin. My project is defined using the maven structure. I was using the postgresql jdbc driver in my pom.xml with
>>>>>
>>>>> <dependency>
>>>>>      <groupId>org.postgresql</groupId>
>>>>>      <artifactId>postgresql</artifactId>
>>>>>      <version>42.2.23</version>
>>>>> </dependency>
>>>>>
>>>>> Hope this helps
>>>>>
>>>>> Tim
>>>>>
>>>>>
>>>>> <OpenPGP_0x7EF42CC581B85618.asc>
>>>>
>>>> #############################################################
>>>> This message is sent to you because you are subscribed to
>>>>    the mailing list <webobjects-dev@wocommunity.org>.
>>>> To unsubscribe, E-mail to: <webobjects-dev-off@wocommunity.org>
>>>> To switch to the DIGEST mode, E-mail to <webobjects-dev-digest@wocommunity.org>
>>>> To switch to the INDEX mode, E-mail to <webobjects-dev-index@wocommunity.org>
>>>> Send administrative queries to <webobjects-dev-request@wocommunity.org>
>>>>
>>>
>>> #############################################################
>>> This message is sent to you because you are subscribed to
>>>  the mailing list <webobjects-dev@wocommunity.org>.
>>> To unsubscribe, E-mail to: <webobjects-dev-off@wocommunity.org>
>>> To switch to the DIGEST mode, E-mail to <webobjects-dev-digest@wocommunity.org>
>>> To switch to the INDEX mode, E-mail to <webobjects-dev-index@wocommunity.org>
>>> Send administrative queries to <webobjects-dev-request@wocommunity.org>
>>>
Subscribe (FEED) Subscribe (DIGEST) Subscribe (INDEX) Unsubscribe Mail to Listmaster