[webfrustrated]

I have removed all the manual code that was creating, committing and rollback a transaction;

In my custom DataSource (AdminDataSource) the execute method is a follows:

public DSResponse execute(DSRequest dsRequest)... {
Connection conn = getTransactionConnection(dsRequest);
JDBCOperations jdbcOps = new JDBCOperations();
jdbcOps.setUser(conn, "NICKLACHEY");
dsResponse.super.execute(dsRequest);
return dsResponse;
}

So I reduced a lot of code here, and there are no manual commits, rollbacks or start or end transaction calls.

I also commented the line in the SecureIDACall to set the TransactionPolicy when instantiating the RPCManager for field level security.

So in the server.properties, uncommented the following: sql.Oracle.autoJoinTransactions:ALL. I have a DMI Handler where I now have the following:

int transPolicy = dsRequest.getRPCManager().getTransactionPolicy();
logger.debug("transaction policy: " + transPolicy);

This still returns 0 (NOT_SET) in the log. Am i setting the policy incorrectly?

[Isomorphic]

Two things - first, you're focused on the RPCManager's policy but that's really just a default. Transaction policy is *per-database* for SQLDataSource.

Second, earlier we confirmed that autoJoinTransactions: ALL would be correct in server.properties, but what you actually want is:

sql.[i]yourDBName[/i].autoJoinTransactions: ALL

With this fix and clarification, if you're going to verify the transactionality of operations, we'd recommend doing so first *without* your stored procedure in the mix, because we suspect its interfering in some way.

[webfrustrated]

Yes, this is exactly what I put in the server.properties file. Here are the settings for your observation:

sql.defaultDatabase: Oracle
sql.Oracle.driver.driverType: oci
sql.Oracle.driver: oracle.jdbc.driver.OracleDriver
sql.Oracle.database.type: jndi
sql.Oracle.driver.name: /jdbc/poolDB
sql.Oracle.autoJoinTransactions: ALL

I have changed my remove operation from calling a stored procedure to the following:

<operationBinding operationType="remove">
<tableClause>ENTITY_TABLE</tableClause>
<whereClause>ENTITY_ID = $values.ENTITY_ID</whereClause>
</operationBinding>

I still see the TransactionPolicy set to 0 in my DMI handler, and the deletion is truly not rolledback after the update statement fails when executed after the execution of the deletion.

When I query the record that should have been rolled back, it is no longer in the database.

[Isomorphic]

OK, this now disagrees with several dozen automated tests that are all passing. Can you please post the complete server log for the request where you see a deletion that is seemingly not rolled back?

[webfrustrated]

14:36:28,403 DEBUG ... SecureIDACall: Entering processRequest
14:36:28,403 DEBUG ... SecureIDACall: session: 354A...
2012-09-07 14:36:28,403 INFO RequestContext - URL: '/sc/IDACall'...
2012-09-07 14:36:28,403 DEBUG XML - Parsed XML from (in memory stream): 0ms
2012-09-07 14:36:28,403 DEBUG RPCManager - Processing 2 requests.
2012-09-07 14:36:28,403 DEBUG PRCManager - Request #1 (DSRequest) payload: {
criteria:{
ENTITY_ID:"23844"
},
operationConfig:{
dataSource:"ENTITY_TABLE",
operationType:"remove"
},
appID:"builtinApplication",
operation:"ENTITY_TABLE_remove",
oldValues:{
ENTITY_ID:"23844"
}
}
2012-09-07 14:36:28,403 DEBUG PRCManager - Request #2 (DSRequest) payload: {
criteria:{
ENTITY_ID:"10001"
},
values:{
ENTITY_ID:10001,
ENTITY_COMMENTS:"testing..."
},
operationConfig:{
dataSource:"ENTITY_TABLE",
operationType:"update"
},
appID:"builtinApplication",
operation:"ENTITY_TABLE_update",
oldValues:{
ENTITY_ID:"10001",
ENTITY_COMMENTS:"testing..."
}
}
14:36:28,403 DEBUG ... SecureIDACall: Calling processRPCTransaction()...
2012-09-07 14:36:28,434 DEBUG AppBase - [builtinApplication.ENTITY_TABLE_remove] No userTypes defined, allowing anyone access to all operations for this application
2012-09-07 14:36:28,434 DEBUG AppBase - [builtinApplication.ENTITY_TABLE_remove] No public zero-argument method named '_ENTITY_TABLE_remove' found, performing generic datasource operation
14:36:28,434 DEBUG ... AdminDataSource: Entering: execute
14:36:28,434 DEBUG ... AdminDataSource: DataSource operation: ENTITY_TABLE_remove
2012-09-07 14:36:28,434 DEBUG PoolableSQLConnectionFactory - [builtinApplication.ENTITY_TABLE_remove] Returning pooled Connection
2012-09-07 14:36:28,434 DEBUG SQLTransaction - [builtinApplication.ENTITY_TABLE_remove] Started new Oracle transaction "23108627"
14:36:28,403 DEBUG ... JDBCOperations: Entering: setUser
14:36:28,403 DEBUG ... JDBCOperations: calling SP_SET_USER(?) for user: JOHNDOE
14:36:28,450 DEBUG ... JDBCOperations: Exiting setUser
14:36:28,450 DEBUG ... AdminDataSource: Exiting setUser
2012-09-07 14:36:28,450 INFO SQLDataSource - [builtinApplication.ENTITY_TABLE_remove] Performing remove operation with criteria: {ENTITY_ID: "23844"} values: {ENTITY_ID: "23844"}
2012-09-07 14:36:28,450 INFO SQLDriver - [builtinApplication.ENTITY_TABLE_remove] Executing SQL update on 'Oracle': DELETE FROM entity_table WHERE entity_id = '23844'
2012-09-07 14:36:28,497 INFO SQLDataSource - remove operation affected 1 rows
14:36:28,450 DEBUG ... AdminDataSource: Exiting execute
2012-09-07 14:36:28,497 DEBUG AppBase - [builtinApplication.ENTITY_TABLE_update] No userTypes defined, allowing anyone access to all operations for this application
2012-09-07 14:36:28,497 DEBUG AppBase - [builtinApplication.ENTITY_TABLE_update] No public zero-argument method named '_ENTITY_TABLE_update' found, performing generic datasource operation
14:36:28,497 DEBUG ... AdminDataSource: Entering: execute
14:36:28,497 DEBUG ... AdminDataSource: DataSource operation: ENTITY_TABLE_update
14:36:28,528 DEBUG ... JDBCOperations: Entering: setUser
14:36:28,528 DEBUG ... JDBCOperations: calling SP_SET_USER(?) for user: JOHNDOE
14:36:28,528 DEBUG ... JDBCOperations: Exiting setUser
14:36:28,528 DEBUG ... AdminDataSource: Exiting setUser
2012-09-07 14:36:28,528 INFO SQLDataSource - [builtinApplication.ENTITY_TABLE_update] Performing update operation with criteria: {ENTITY_ID: "10001"} values: {ENTITY_ID: "10001"}
2012-09-07 14:36:28,528 INFO SQLDriver - [builtinApplication.ENTITY_TABLE_update] Executing SQL update on 'Oracle': UPDATE ENTITY_TABLE SET ENTITY_COMMENTS='testing...' WHERE (ENTITY_ID = '23844')
2012-09-07 14:36:28,528 WARN RequestContext - dsRequest.execute() failed:
java.sql.SQLException: ORA-20999: test exception
ORA-06512...
2012-09-07 14:36:28,653 DEBUG Rolling back Oracle transaction "23108627"
2012-09-07 14:36:28,653 DEBUG RPCManager - non DMI response, dropExtraFields: false
2012-09-07 14:36:28,653 DEBUG RPCManager - non DMI response, dropExtraFields: false
2012-09-07 14:36:28,653 DEBUG Ending Oracle transaction "23108627"
14:36:28,669 SecureIDACall: Exiting: processRequest

We have implemented a custom pop up window to display a data error. Once this data error is displayed, I query the ENTITY_TABLE in Oracle, and the record (ENTITY_ID = '23844') is no longer in the table.

I believe that I am setting the TransactionPolicy correctly in my server.properties Oracle database configuration. The log shows 2 database request executed within a single transaction and database connection. Even if I use a DMI handler, the TransactionPolicy value shows 0 when I put a debug statement in the DMI handler.

[Isomorphic]

This log is puzzling. The setting of the transaction policy is an unimportant detail at this point, because you can see the explicit rollback in the log. That message is logged immediately before we issue a rollback() call on the JDBC connection, so it seems like the delete could only succeed if it was using a different connection, or autoCommit is on. However, neither of these seem likely. There is only one log entry indicating the return of a connection, and the message

Started new Oracle transaction "23108627"

is sent immediately after we explicitly set autoCommit to false on the connection we've just obtained.

Just to confirm, all our transaction-based automated tests are passing when run against Oracle (and all other databases), and a test that we wrote specifically to mirror your failing case also passes OK.

It would be interesting to know if the response for the first operation (the delete) has a status of 1 or -10. Also, can you try this with with a recent 3.1d nightly build, and post the log? That version of the software has even more detailed and explicit logging of connection information - the 3.1d logs should show conclusively that it is definitely using the same connection for both updates. If it is (as we fully expect), we then have to start questioning the JDBC driver. Actually, another useful test would be to try with with the "thin" driver rather than the OCI one - does that make a difference?

[webfrustrated]

So I finally figured out the problem. I did test to see if the thin driver vs. the oci driver made a difference which it did not. I also tried the different oracle drivers, classes12 vs. ojdbc14, and this made no difference as well.

I issue was at our end, but it took some digging to figure it out. In our call to SP_SET_USER(?) which gets called before every database operation, there was a "commit" being issued at the very bottom of the stored procedure. This is what was happening:

1. call to SP_SET_USER(?) - commit issued in stored proc
2. call to delete the entity either thru SQL or stored proc
3. call to SP_SET_USER(?) - commit issued in stored proc which commited the previous deletion
4. call to update the entity with a trigger to throw SQL exception and force rollback

I have removed the commit from SP_SET_USER(?), and things seem to be working as anticipated. Thanks for helping us troubleshoot this issue.