[DERBY-4299] Slave start fails with message that the database is already booted, even when it is not.

• Type: Bug
• Status: Reopened
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 10.5.1.1, 10.6.1.0
• Component/s: Network Server, Replication
• Labels: derby_triage10_9
• Environment: java version "1.6.0_13"; Java(TM) SE Runtime Environment (build 1.6.0_13-b03); Java HotSpot(TM) Client VM (build 11.3-b02, mixed mode); ; SunOS opensolaris 5.11 snv_117 i86pc i386 i86pc Solaris
• Urgency: Normal
• Issue & fix info: Repro attached, Workaround attached
• Bug behavior facts: Crash, Seen in production
• Assignee: Unassigned
• Reporter: Dag H. Wanvik
• Created: 10/Jul/09 14:36
• Updated: 21/Feb/12 19:35

Description

Seen by Alan Burlison, cf. http://mail-archives.apache.org/mod_mbox/db-derby-user/200907.mbox/ajax/[e-mail]%3e

ij> connect
'jdbc:derby://bleaklow/opensolaris;user=auth;password=CHANGEME;securityMechanism=8;startSlave=true';
ERROR XRE09: DERBY SQL error: SQLCODE: -1, SQLSTATE: XRE09, SQLERRMC:
Cannot start replication slave mode for database 'opensolaris'. The
database has already been booted.

I can reproduce it using Alan's database (thanks, Alan!). When running a debug build of Derby, however, I hit an ASSERT:
ASSERT FAILED Wrong LogInstant on log record (0,0) version real position (4,3304)
at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
at org.apache.derby.impl.store.raw.log.Scan.getNextRecordBackward(Scan.java:403)
at org.apache.derby.impl.store.raw.log.Scan.getNextRecord(Scan.java:204)
at org.apache.derby.impl.store.raw.log.FileLogger.undo(FileLogger.java:939)
at org.apache.derby.impl.store.raw.xact.Xact.abort(Xact.java:949)
at org.apache.derby.impl.store.raw.xact.Xact.destroy(Xact.java:1105)
at org.apache.derby.impl.store.access.RAMTransaction.destroy(RAMTransaction.java:2030)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.boot(DataDictionaryImpl.java:802)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:2021)
at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:333)
at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:573)
at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java:214)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:2021)
at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:333)
at org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1858)
at org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(BaseMonitor.java:1724)
at org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(BaseMonitor.java:1602)
at org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(BaseMonitor.java:1021)
at org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Monitor.java:550)
at org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2580)

so there seems to be an issue with the log. It could be related to DERBY-3896. In Alan's original repre he used client/Server mode, but I can reproduce the error with embedded more, cf. the attached script.

Issue Links

• is related to: DERBY-3896 Assert failure in LogicalUndoOperation.doMe() when starting slave with uncommitted transactions on the master
• relates to: DERBY-4196 Document initiation of replication from cleanly shut down database