You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@openjpa.apache.org by mysakjs <my...@us.ibm.com> on 2013/07/12 06:12:59 UTC

record delete during flo

I am seeing a strange problem where a SELECT is resulting in a subsequent and
seemingly automatic delete.   A subset of the stack trace follows.    Any
ideas what might cause this from a JPA perspective.

After doing some searching it sounds like:   SQLCODE=-727, SQLSTATE=56098,
SQLERRMC=2
can be  associated with a database being in an "error" state.   If that is
the case here,  can that cause JPA to perform a delete after a SELECT?  
That doesn't sound right, but I'm not really coming up with any reasonable
theories on what could be causing the DELETE.   

I've enabled openjpa tracing, and there's not many clues in the logs, but
I'm still going over them.  

I can't find anywhere in our code where there is an explicit delete, and am
a bit baffled at the moment, why this is happening. 

Thanks in advance for any insights/ ideas. 

Caused by: <openjpa-2.2.1-SNAPSHOT-r422266:1363644 fatal general error>
org.apache.openjpa.persistence.PersistenceException: DB2 SQL Error:
SQLCODE=-727, SQLSTATE=56098,
SQLERRMC=2;-551;42501;<user>|DELETE|<table_name>, DRIVER=3.63.75
FailedObject: prepstmnt -1693313274 DELETE FROM <table_name> WHERE id = ?
[org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement]
        at
org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4946)
        at
org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4906)
        at
org.apache.openjpa.jdbc.sql.DB2Dictionary.newStoreException(DB2Dictionary.java:564)
        at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:136)
        at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:78)
        at
org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushBatch(BatchingPreparedStatementManagerImpl.java:226)
        at
org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(BatchingConstraintUpdateManager.java:63)
        at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:105)
        at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:78)
        at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:735)
        at
org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
        ... 96 more
Caused by: com.ibm.db2.jcc.am.SqlException: DB2 SQL Error: SQLCODE=-727,
SQLSTATE=56098, SQLERRMC=2;-551;42501;<user>|DELETE|<table_name>,
DRIVER=3.63.75
        at com.ibm.db2.jcc.am.fd.a(fd.java:682)
        at com.ibm.db2.jcc.am.fd.a(fd.java:60)
        at com.ibm.db2.jcc.am.fd.a(fd.java:127)




--
View this message in context: http://openjpa.208410.n2.nabble.com/record-delete-during-flo-tp7584399.html
Sent from the OpenJPA Users mailing list archive at Nabble.com.

Re: record delete during flo

Posted by Jeremy Bauer <te...@gmail.com>.
Glad to hear you were able to resolve this issue.  Thanks for replying back
to the list.

-Jeremy

On Mon, Jul 15, 2013 at 5:54 PM, mysakjs <my...@us.ibm.com> wrote:

> Update:   This turned out to be a code issue.    The managed entity was
> being
> updated in an unexpected location and when the transaction was committed
> the
> associated db rows were deleted.   So this does not appear to be a JPA
> issue,  but a code issue.
>
>
>
> --
> View this message in context:
> http://openjpa.208410.n2.nabble.com/record-delete-during-flo-tp7584399p7584424.html
> Sent from the OpenJPA Users mailing list archive at Nabble.com.
>

Re: record delete during flo

Posted by mysakjs <my...@us.ibm.com>.
Update:   This turned out to be a code issue.    The managed entity was being
updated in an unexpected location and when the transaction was committed the
associated db rows were deleted.   So this does not appear to be a JPA
issue,  but a code issue. 



--
View this message in context: http://openjpa.208410.n2.nabble.com/record-delete-during-flo-tp7584399p7584424.html
Sent from the OpenJPA Users mailing list archive at Nabble.com.

Re: record delete during flo

Posted by mysakjs <my...@us.ibm.com>.
Please ignore the above exception.   That is most likely occurring when I had
the database user DELETE permissions revoked to see where an exception might
be thrown, to better understand what is causing the seemingly phantom DELETE
activity (after a SELECT).   

The thing interesting is the SELECT query , that results in a subsequent
unexpected and unwanted DELETE (for no apparent reason) has a lot of LEFT
OUTER JOINS due to EAGER fetching of data in 1 : many relationships.   It
appears from the openjpa trace there's about 6 of them.  (left outer joins).  
I don't know if that could be contributing to the problem and I wouldn't
think so, but I thought I'd mention it anyway.

Here's all that seems to be logged in the openjpa trace all (in WAS 8.5)
when the unwanted DELETE is occuring, when the permissions are restored and
the db user is allowed to DELETE:

[7/12/13 0:29:27:681 EDT] 0000009d OpenJPA       3   openjpa.jdbc.JDBC:
Trace: <t 922525506, conn 500988834> [0 ms] close
[7/12/13 0:29:27:682 EDT] 0000009d OpenJPA       3   openjpa.jdbc.SQLDiag:
Trace: flush: org.apache.openjpa.kernel.PDirtyState for oid=103546
[7/12/13 0:29:27:682 EDT] 0000009d OpenJPA       3   openjpa.jdbc.JDBC:
Trace: The batch limit is set to 100.
[7/12/13 0:29:27:682 EDT] 0000009d OpenJPA       3   openjpa.jdbc.JDBC:
Trace: <t 922525506, conn 190483185> [0 ms] close

Not sure if this provides any clues, but I'll search on it.    In addition
to PDirtyState  I have also seen messages logged for PDeletedState... right
before the DELETE happens.

[7/12/13 0:27:55:527 EDT] 00000099 OpenJPA       3   openjpa.jdbc.SQLDiag:
Trace: flush: org.apache.openjpa.kernel.PDirtyState for oid=103541
[7/12/13 0:27:55:527 EDT] 00000099 OpenJPA       3   openjpa.jdbc.SQLDiag:
Trace: flush: org.apache.openjpa.kernel.PDeletedState for oid=51850
[7/12/13 0:27:55:528 EDT] 00000099 OpenJPA       3   openjpa.jdbc.JDBC:
Trace: The batch limit is set to 100.
[7/12/13 0:27:55:528 EDT] 00000099 OpenJPA       3   openjpa.jdbc.SQL:
Trace: <t 391662123, conn -22357016> executing prepstmnt -1292669644 DELETE
FROM <table_name> WHERE id = ? [params=?]




--
View this message in context: http://openjpa.208410.n2.nabble.com/record-delete-during-flo-tp7584399p7584400.html
Sent from the OpenJPA Users mailing list archive at Nabble.com.