History | Log In     View a printable version of the current page.  
Issue Details (XML | Word | Printable)

Key: BRUCE-3
Type: Bug Bug
Status: Reopened Reopened
Priority: Minor Minor
Assignee: Robert Klahn
Reporter: Robert Klahn
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
Bruce

Possible problem with the LogSwitchThread

Created: 05/Jul/07 12:57 PM   Updated: 19/Oct/07 01:42 PM
Component/s: Daemon
Affects Version/s: 0.5
Fix Version/s: 1.5

Time Tracking:
Not Specified

Environment: server: rakdev. F-7 i386, Pg 8.2, Bruce r12 + some local mods to address ticket BRUCE-1


 Description  « Hide
First of all, Im not even sure this is a problem. Just opening a ticket for later investigation.

From bruce.log, in in short order:

INFO Thread-8 com.netblue.bruce.LogSwitchThread - Time to drop old tables.
INFO Thread-8 com.netblue.bruce.LogSwitchThread - Dropping bruce.transactionlog_3 and bruce.snapshotlog_3
INFO Thread-7 com.netblue.bruce.SlaveFactory - [Cluster One]: spawning slave thread for node: cluster one - slave zwei
INFO Thread-7 com.netblue.bruce.SlaveFactory - [Cluster One]: spawning slave thread for node: cluster one - slave ein
WARN cluster one - slave zwei com.netblue.bruce.SnapshotCache - Unable to obtain NEXT snapshot from database
org.postgresql.util.PSQLException: ERROR: could not open relation with OID 16603
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1525)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1309)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:188)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:354)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:258)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
at com.netblue.bruce.SnapshotCache.getNextSnapshot(SnapshotCache.java:230)
at com.netblue.bruce.SlaveRunner.getNextSnapshot(SlaveRunner.java:353)
at com.netblue.bruce.SlaveRunner.run(SlaveRunner.java:203)
at java.lang.Thread.run(Thread.java:595)



 All   Comments   Work Log   Change History      Sort Order: Ascending order - Click to sort in descending order
Robert Klahn - 05/Jul/07 06:22 PM
Happened a second time (in the same run of the daemon, btw):

INFO Thread-8 com.netblue.bruce.LogSwitchThread - Time to drop old tables.
INFO Thread-8 com.netblue.bruce.LogSwitchThread - Dropping bruce.transactionlog_4 and bruce.snapshotlog_4
WARN cluster one - slave zwei com.netblue.bruce.SnapshotCache - Unable to obtain NEXT snapshot from database
org.postgresql.util.PSQLException: ERROR: could not open relation with OID 16609
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1525)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1309)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:188)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:354)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:258)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
at com.netblue.bruce.SnapshotCache.getNextSnapshot(SnapshotCache.java:230)
at com.netblue.bruce.SlaveRunner.getNextSnapshot(SlaveRunner.java:353)
at com.netblue.bruce.SlaveRunner.run(SlaveRunner.java:203)
at java.lang.Thread.run(Thread.java:595)


Lance Ball - 06/Jul/07 03:44 PM
I looked into this a little today and found that a fix will probably come from changing the transaction isolation level on the slave connection.

Lance Ball - 06/Jul/07 03:47 PM
This should be resolved in changeset http://fisheye.codehaus.org/changelog/bruce/?cs=28

Changed the transaction isolation level on the JDBC Connection to TRANSACTION_REPEATABLE_READ. The default level, TRANSACTION_READ_COMMITTED will allow non-repeatable reads. Non-repeatable reads happen when a query returns data that would be different if the query were repeated within the same transaction. Non-repeatable reads can occur when other transactions are modifying data that a transaction is reading.

This seems to address the Jira issue in BRUCE-3. It appears that the SlaveRunner was selecting from the snapshotlog view while the LogSwitchThread was switching out the underlying tables. TRANSACTIONAL_REPEATABLE_READ should address this. Phantom reads not possible because entire table is locked.

More info at: http://publib.boulder.ibm.com/infocenter/cscv/v10r1/index.jsp?topic=/com.ibm.cloudscape.doc/cdevconcepts15366.html

http://books.google.com/books?id=LjXBeAWM-KgC&pg=RA6-PA391&lpg=RA6-PA391&dq=default+jdbc+transaction+isolation+level+postgresql&source=web&ots=fi6TUk2iwC&sig=r6X0TswV1hr3Y0YjYkP0iy4jFj4


Robert Klahn - 09/Aug/07 06:02 PM
Afraid this is still a problem against bruce-0.5
 
INFO LogSwitch com.netblue.bruce.LogSwitchThread - Time to drop old tables.
INFO LogSwitch com.netblue.bruce.LogSwitchThread - Dropping bruce.transactionlog_4 and bruce.snapshotlog_4
WARN db-bimp.ww - Slave new-db-bimp.ww com.netblue.bruce.SnapshotCache - Unable to obtain NEXT snapshot from database
org.postgresql.util.PSQLException: ERROR: relation 20420 deleted while still in use
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1525)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1309)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:188)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:354)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:258)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
        at com.netblue.bruce.SnapshotCache.getNextSnapshot(SnapshotCache.java:230)
        at com.netblue.bruce.SlaveRunner.getNextSnapshot(SlaveRunner.java:368)
        at com.netblue.bruce.SlaveRunner.run(SlaveRunner.java:218)
        at java.lang.Thread.run(Thread.java:595)
bINFO LogSwitch com.netblue.bruce.LogSwitchThread - Time to create a new log table.
INFO LogSwitch com.netblue.bruce.LogSwitchThread - New Transaction Table Name is:bruce.transactionlog_9
INFO LogSwitch com.netblue.bruce.LogSwitchThread - New Snapshot Table Name is:bruce.snapshotlog_9
WARN db-bimp.ww - Slave db-bimp-mirror.ww com.netblue.bruce.SnapshotCache - Unable to obtain NEXT snapshot from database
org.postgresql.util.PSQLException: ERROR: relation 22795 deleted while still in use
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1525)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1309)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:188)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:354)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:258)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
        at com.netblue.bruce.SnapshotCache.getNextSnapshot(SnapshotCache.java:230)
        at com.netblue.bruce.SlaveRunner.getNextSnapshot(SlaveRunner.java:368)
        at com.netblue.bruce.SlaveRunner.run(SlaveRunner.java:218)
        at java.lang.Thread.run(Thread.java:595)