You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Olav Sandstaa (JIRA)" <ji...@apache.org> on 2007/01/18 21:21:30 UTC
[jira] Created: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Assert during log file switch: log file position exceeded max log file size
---------------------------------------------------------------------------
Key: DERBY-2254
URL: https://issues.apache.org/jira/browse/DERBY-2254
Project: Derby
Issue Type: Bug
Components: Store
Affects Versions: 10.3.0.0
Environment: Solaris 10, Java SE 6 build 104
Reporter: Olav Sandstaa
When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
This seems to occur during a switch to a new log file.
derby.log contains the following call stack for the background thread:
Exception trace:
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
at java.lang.Thread.run(Thread.java:619)
2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
at java.lang.Thread.run(Thread.java:619)
Cleanup action completed
For my user threads the call stack is similar:
Database Class Loader started - derby.database.classpath=''
2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
After this it seems like no user threads are able to connect to the database (not surpricing).
This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
Adding Performance tests .. (was Re: [jira] Created: (DERBY-2254)
Assert during log file switch: log file position exceeded max log file size)
Posted by Sunitha Kambhampati <ks...@gmail.com>.
Olav Sandstaa (JIRA) wrote:
>When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following
>
>
Dan and myself have been working on contributing the Order Entry
benchmark (based on TPC-C) as part of DERBY-1987. I think your TPC-B
like transaction benchmark might be a good addition for Derby
performance tests. Is this something that you may want to contribute to
Derby ?.
We have a basic perf framework using Junit. (see DERBY-1987,
DERBY-2200). The performance framework could use more enhancements..
Also there is a page on the wiki for this.
http://wiki.apache.org/db-derby/DerbyPerfTesting
Thanks,
Sunitha.
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Olav Sandstaa (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12465881 ]
Olav Sandstaa commented on DERBY-2254:
--------------------------------------
The crash happened when running simple transactions (3 updates, 1
insert, 1 select) against a database with 10 GB user data (total data
volume 17 GB). Derby was configured with a 18 GB database buffer. The
crash occured about 2 hours after re-starting an existing
database. The load consisted of 64 clients running transactions
back-to-back. Since the database was "just" started most of the
transactions had to read data from the disk, thus there were about 60
concurrent read requests for getting data into the database buffer. At
the same time the single back-ground thread was having a hard time to
keep up writing out dirty data to the disk. At this time there were
plenty of free room in the page cache so no data blocks were "evicted"
out to disk by the user threads.
Since the background thread were not able to flush data pages fast
enough it was also unable to reclaim log files. So the amount of log
kept growing.
One thing I do not understand is that most of the log files have their
normal size while some are very close to the max log file size. Here
is a list of the files in the log directory after the crash:
-rw-r----- 1 olav 48 Jan 17 22:09 log.ctrl
-rw-r----- 1 olav 48 Jan 17 22:09 logmirror.ctrl
-rw-r----- 1 olav 1060411 Jan 17 22:09 log1181.dat
-rw-r----- 1 olav 1067038 Jan 17 22:09 log1182.dat
-rw-r----- 1 olav 1049488 Jan 17 22:09 log1183.dat
-rw-r----- 1 olav 1050176 Jan 17 22:09 log1184.dat
-rw-r----- 1 olav 1050758 Jan 17 22:10 log1185.dat
-rw-r----- 1 olav 1050583 Jan 17 22:10 log1186.dat
-rw-r----- 1 olav 1050178 Jan 17 22:10 log1187.dat
-rw-r----- 1 olav 1054465 Jan 17 22:10 log1188.dat
-rw-r----- 1 olav 1051730 Jan 17 22:11 log1189.dat
-rw-r----- 1 olav 1052601 Jan 17 22:11 log1190.dat
-rw-r----- 1 olav 268435436 Jan 17 22:55 log1191.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1192.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1193.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1194.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1195.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1196.dat
-rw-r----- 1 olav 1048576 Jan 17 22:55 log1197.dat
-rw-r----- 1 olav 268435434 Jan 17 23:23 log1198.dat
-rw-r----- 1 olav 1048576 Jan 17 23:23 log1199.dat
-rw-r----- 1 olav 1048576 Jan 17 23:23 log1200.dat
-rw-r----- 1 olav 1048576 Jan 17 23:23 log1201.dat
-rw-r----- 1 olav 1048576 Jan 17 23:23 log1202.dat
-rw-r----- 1 olav 268435429 Jan 17 23:46 log1203.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1204.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1205.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1206.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1207.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1208.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1209.dat
-rw-r----- 1 olav 1048576 Jan 17 23:46 log1210.dat
-rw-r----- 1 olav 268435456 Jan 18 00:09 log1211.dat
-rw-r----- 1 olav 0 Jan 18 00:09 log1212.dat
In org.apache.derby.impl.store.raw.log.LogCounter the following constant is defined
// reserve top 4 bits in log file size for future use
public static final long MAX_LOGFILE_SIZE = (long)0x0FFFFFFFL; // 268435455
and the assert is defined as:
SanityManager.ASSERT(filepos < MAX_LOGFILE_SIZE,
"log file position exceeded max log file size");
Comparing the constant MAX_LOGFILE_SIZE (268435455) with the length of
the second last file above (268435456) it actually seems like this log
file has become a byte too long.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Olav Sandstaa (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466490 ]
Olav Sandstaa commented on DERBY-2254:
--------------------------------------
Just for the record: I tried to restart the database to see if it was able to recover. Not surpricingly, after about three hours into the recovery, it was aborted with the same assert and the following call stack:
Exception trace:
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.Scan.getNextRecordForward(Scan.java:973)
at org.apache.derby.impl.store.raw.log.Scan.getNextRecord(Scan.java:206) at org.apache.derby.impl.store.raw.log.FileLogger.redo(FileLogger.java:1176)
at org.apache.derby.impl.store.raw.log.LogToFile.recover(LogToFile.java:811)
at org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java:308)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1994)
at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:291)
at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:546)
at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:419)
at org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java:988)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1994)
at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:291)
at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:546)
at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:419)
at org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java:746)
at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java:182)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1994)
at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:291)
at org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1829)
at org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(BaseMonitor.java:1695)
at org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(BaseMonitor.java:1575)
at org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(BaseMonitor.java:994)
at org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Monitor.java:542)
at org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:1633)
at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:223)
at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java:73)
at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(EmbedConnection40.java:54)
at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Driver40.java:64)
at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:210)
at org.apache.derby.jdbc.AutoloadedDriver.connect(AutoloadedDriver.java:117)
at java.sql.DriverManager.getConnection(DriverManager.java:582)
at java.sql.DriverManager.getConnection(DriverManager.java:185)
at com.sun.derby.perf.clients.tpcb.DBConnection.loadDriver(DBConnection.java:140)
at com.sun.derby.perf.clients.tpcb.DBConnection.<init>(DBConnection.java:49)
at com.sun.derby.perf.clients.tpcb.TPCBClient.run(TPCBClient.java:132)
at com.sun.derby.perf.clients.tpcb.TPCBClient.main(TPCBClient.java:381)
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
Re: [jira] Commented: (DERBY-2254) Assert during log file switch:
log file position exceeded max log file size
Posted by Suresh Thalamati <su...@gmail.com>.
Hi Olav,
Thanks a lot for spending time to find the cause for the large log
files. My comments are in-line.
Olav Sandstaa wrote:
> Suresh
> Suresh Thalamati wrote:
>
>> Olav Sandstaa (JIRA) wrote:
>>
>>> [
>>> https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466475
>>> ]
>>> Olav Sandstaa commented on DERBY-2254:
>>> --------------------------------------
>
> I have tried running with these settings and the resulting 3.2 GB
> derby.log file contains the dump of about 16 million log records. The
> last entries in the log are:
>
>
<snip > ..
>
> As you suggested, I tried to look for any sign of whether a checkpoint
> was in progress or not. But from the dump of the log I can not find any
> sign of checkpoints in the entire log. Do you have any suggestions for
> how a checkpoint would identify itself in the log dump?
Checkpoint in the log trace , should look something like the following :
DEBUG LogTrace OUTPUT: scanned 160 : Checkpoint : redoLWM (1,49176)
undoLWM (1,49176)
**************************
org.apache.derby.impl.store.raw.xact.TransactionTable@bf7190
..etc.
I was thinking there should be a checkpoint in log files around
the large log files,(log1191.dat (log1191.dat log1198.dat ..)
not necessarily in the them.
Only other reason I can think for not finding a checkpoint is ,
it started in the beginning and never finished. If this the case
then I am confused how it managed to generate ~1MB log files in
between those large ones.
>
> If I try to categorize the entries in the log dump they fall into the
> following types (with the number of occurrences in the first column):
>
> 11422649 Page Operation:
> 2340723 BeginXact
> 2340734 EndXact
> 420947 Checksum Operation
> 29 detected proper log end on log file
> 29 switched to next log file
>
> None of these seems to indicate that a checkpoint have started?
>
you are correct, those records can not confirm that the checkpoint in
progress. Checkpoint log records is written only after all the data
is flushed, in your test case failure seems to have occured while
writing a checkpoint record. Looking at the last entries may not be
be useful.
Thanks
-suresht
Re: [jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by Olav Sandstaa <Ol...@Sun.COM>.
Suresh,
Thanks for the information about log switches and checkpoints. I had to
use this server for some other work, but now I have restored the crashed
Derby database and started to look into the failing log files. See
comments inline.
Suresh Thalamati wrote:
> Olav Sandstaa (JIRA) wrote:
>> [
>> https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466475
>> ]
>> Olav Sandstaa commented on DERBY-2254:
>> --------------------------------------
>>
>> Mike, thank you for commenting on this and for explaining what you
>> think are the issues behind this problem. I agree that the best
>> solution seems be to fix this so that the background thread can do
>> log file switching without waiting for the checkpoing to complete.
>
> checkpoint and log switch can run in parallel (NOT sure we ever tested
> this case though ). I think problem here is we are dumping both the
> requests on to the same thread. It is more of performance issues.
> May be in the future log switches/checkpoints/... should be processed
> on different threads, when cache is configured with large size.
>
> I think some log size calculations are wrong, if this bug is fixed
> Derby should still work by correctly switching log file before
> hitting the MAX limit.
>
>
>>
>> Some questions somebody maybe know the answer to:
>>
>> -What is the reason for most of the log files having the default
>> size of 1 MB but a few (4) log files grow to 268 kB before
>> switching?
>>
>
>
>
> Default log file size to start a Log switch is 1MB and to perform a
> checkpoint is 10MB. Normally log switch requests are processed by
> rawStoreDaemon(checkpoint Daemon) thread without blocking the user
> threads for switch to complete.
>
> Log switch happens is following three scenarios:
>
> 1) On log flush call if it finds current log file size > configure log
> file size, then log switch request is placed on the rawstore daemon
> thread.
>
> 2) As part of checkpoint , log switch is done before performing the
> checkpoint if log file size > configured log file size.
>
> 3) While writing log records if it finds the log file size has
> reached the MAX_LIMIT.
>
> 4) During backup, to backup full log files instead of partial portions.
>
> By looking at the log file sizes you posted my guess is LOG SWITCH
> requests are getting struck behind the checkpoint request. I would
> think with 18GB cache, checkpoint must be taking long time.
>
> Another case log file size grow bigger than configured size is if the
> transactions are long and nothing in the database triggered a flush
> call. I am guessing that is not case here , your application must be
> doing frequent commits; otherwise it is unlikely that there are 1M log
> files.
You are right. The test produces small transactions consisting of only
five operations. So it is not the length of the transactions that make
the log files grow very large.
>
>> -The crash occurs after having produced about 1 GB of log. Is there
>> a hard limit on 1 GB before the checkpoint must be completed?
>
>
> I have not seen any such limit. Unless you have changed the defaults
> checkpoint is requested every 10MB , unless checkpoint is already in
> progress. I think the checkpoint are taking long time, parallel
> activity is producing lot of log. By the way how did you come up
> with 1GB number ?
I have not changed any defaults. The reason for asking if there was
something related to 1 GB of log was probably due to I misunderstood a
comment Mike made (qoute from DERBY-2254: "my best guess is that the
act of switching the log file at 1 gig has become stuck behind finishing
the checkpoint").
> I see only few 1MB log files and huge files in
> between (268 MB)... My guess is checkpoint is is in progress when
> those large files are being created.
>
> If you want to confirm this hypothesis, you can dump the whole log on
> recovery, or just modify the code to print only checkpoints from the
> log. you can dump the log by setting the following flags in the debug
> code line :
>
> derby.debug.true=DumpLogOnly
> derby.storage.logDumpStart=49
I have tried running with these settings and the resulting 3.2 GB
derby.log file contains the dump of about 16 million log records. The
last entries in the log are:
DEBUG LogTrace OUTPUT: scanned 12632271 : EndXact null Committed :
transactionStatus = Committed instant = (1211,268435242) logEnd =
(1211,268435277) logIn at 15 available 4
DEBUG LogTrace OUTPUT: scanned 12632266 : Page Operation:
Page(33,Container(0, 960)) pageVersion 176243 : Update Slot=8
recordId=14 instant = (1211,268435277) logEnd = (1211,268435346) logIn
at 24 available 29
DEBUG LogTrace OUTPUT: scanned 12632266 : EndXact null Committed :
transactionStatus = Committed instant = (1211,268435346) logEnd =
(1211,268435381) logIn at 15 available 4
DEBUG LogTrace OUTPUT: scanned Null : Checksum Operation algorithm = 1
value = 2138849209 data length= 38 instant = (1211,268435381) logEnd =
(1211,268435418)
As you suggested, I tried to look for any sign of whether a checkpoint
was in progress or not. But from the dump of the log I can not find any
sign of checkpoints in the entire log. Do you have any suggestions for
how a checkpoint would identify itself in the log dump?
If I try to categorize the entries in the log dump they fall into the
following types (with the number of occurrences in the first column):
11422649 Page Operation:
2340723 BeginXact
2340734 EndXact
420947 Checksum Operation
29 detected proper log end on log file
29 switched to next log file
None of these seems to indicate that a checkpoint have started?
Regards,
Olav
Re: [jira] Commented: (DERBY-2254) Assert during log file switch:
log file position exceeded max log file size
Posted by Suresh Thalamati <su...@gmail.com>.
Olav Sandstaa (JIRA) wrote:
> [ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466475 ]
>
> Olav Sandstaa commented on DERBY-2254:
> --------------------------------------
>
> Mike, thank you for commenting on this and for explaining what you
> think are the issues behind this problem. I agree that the best
> solution seems be to fix this so that the background thread can do
> log file switching without waiting for the checkpoing to complete.
checkpoint and log switch can run in parallel (NOT sure we ever tested
this case though ). I think problem here is we are dumping both the
requests on to the same thread. It is more of performance issues.
May be in the future log switches/checkpoints/... should be processed
on different threads, when cache is configured with large size.
I think some log size calculations are wrong, if this bug is fixed
Derby should still work by correctly switching log file before
hitting the MAX limit.
>
> Some questions somebody maybe know the answer to:
>
> -What is the reason for most of the log files having the default
> size of 1 MB but a few (4) log files grow to 268 kB before
> switching?
>
Default log file size to start a Log switch is 1MB and to perform a
checkpoint is 10MB. Normally log switch requests are processed by
rawStoreDaemon(checkpoint Daemon) thread without blocking the user
threads for switch to complete.
Log switch happens is following three scenarios:
1) On log flush call if it finds current log file size > configure log
file size, then log switch request is placed on the rawstore daemon
thread.
2) As part of checkpoint , log switch is done before performing the
checkpoint if log file size > configured log file size.
3) While writing log records if it finds the log file size has
reached the MAX_LIMIT.
4) During backup, to backup full log files instead of partial portions.
By looking at the log file sizes you posted my guess is LOG SWITCH
requests are getting struck behind the checkpoint request. I would
think with 18GB cache, checkpoint must be taking long time.
Another case log file size grow bigger than configured size is if the
transactions are long and nothing in the database triggered a flush
call. I am guessing that is not case here , your application must be
doing frequent commits; otherwise it is unlikely that there are 1M log
files.
> -The crash occurs after having produced about 1 GB of log. Is there
> a hard limit on 1 GB before the checkpoint must be completed?
I have not seen any such limit. Unless you have changed the defaults
checkpoint is requested every 10MB , unless checkpoint is already in
progress. I think the checkpoint are taking long time, parallel
activity is producing lot of log. By the way how did you come up
with 1GB number ? I see only few 1MB log files and huge files in
between (268 MB)... My guess is checkpoint is is in progress when
those large files are being created.
If you want to confirm this hypothesis, you can dump the whole log on
recovery, or just modify the code to print only checkpoints from the
log. you can dump the log by setting the following flags in the debug
code line :
derby.debug.true=DumpLogOnly
derby.storage.logDumpStart=49
>
> This crash happened during some experimental testing where I want to
> study data rates to and from the disks during high load. I can do this
> with a much smaller database buffer so being able to run with a 18 GB
> database buffer is not an urgent issue for me right now.
>
Thanks
-suresh
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Olav Sandstaa (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466475 ]
Olav Sandstaa commented on DERBY-2254:
--------------------------------------
Mike, thank you for commenting on this and for explaining what you
think are the issues behind this problem. I agree that the best
solution seems be to fix this so that the background thread can do
log file switching without waiting for the checkpoing to complete.
Some questions somebody maybe know the answer to:
-What is the reason for most of the log files having the default
size of 1 MB but a few (4) log files grow to 268 kB before
switching?
-The crash occurs after having produced about 1 GB of log. Is there
a hard limit on 1 GB before the checkpoint must be completed?
This crash happened during some experimental testing where I want to
study data rates to and from the disks during high load. I can do this
with a much smaller database buffer so being able to run with a 18 GB
database buffer is not an urgent issue for me right now.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Updated: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Mike Matrigali (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mike Matrigali updated DERBY-2254:
----------------------------------
Deleting the log file is the easiest way to guarantee corruption in the derby database. It is impossible to know what kind of
corruption might have happened but all the following are possible, because derby rely's on the info in the log file to maintain
consistent data. Because of in memory database caching the database files on disk may be severely out of date/inconsistent without proper recovery processing using the log files. All the following corruptions are possible when one deletes one or more
log files:
transaction inconsistent data between tables - many of these inconsistencies can't be determined by derby
inconsistent data between base tables and indexes - running the consistency checker does a good job of checking for this
inconsistent data in long rows - a long row may stretch across many pages and the links depend on tranactional consistency if this
is broken a number of runtime errors may occur
inconsistent data in long columns - similar to long row a single column may be linked across many pages and this consistency is
maintained by the transaction log.
If it is ever necessary to remove the log because of some derby bug the only safe thing to do is to go back to your more recent
backup. If you don't have one, what I usually tell users is to assume the db they are accessing is corrupt but accessible. The only
safe thing at that point is to data mine the existing db to copy whatever data looks good out to a file and then load it into a newly
created db. Otherwise one will never know if future errors you encounter in the db are because of this failed recovery.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.1.4
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Mike Matrigali (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mike Matrigali updated DERBY-2254:
----------------------------------
It would also be good from a performance standpoint to minimize the amount of data written to a log file over it's preallocated size, as on some systems those writes cost twice as much as writes to the preallocated size.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Updated: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Mike Matrigali (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mike Matrigali updated DERBY-2254:
----------------------------------
Also wanted to note that this max limit is really a hard limit as the log address can only properly address files in this range. Once you go over that size we can't properly address records in that file.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "quartz (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12556927#action_12556927 ]
quartz commented on DERBY-2254:
-------------------------------
Because stored procedure call SYSCS_UTIL.SYSCS_COMPRESS_TABLE(.....)
cannot run concurrently with inserts (see #DERBY-1068)
our log file grows like crazy. I suppose either inserts goes really slow, or to a halt and backlog in the log file.
Eventually, it crashes. Dead for good. Irrecoverable.
We can't wait for a fix...
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.1.4
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Mike Matrigali (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mike Matrigali updated DERBY-2254:
----------------------------------
This is very interesting, you are definitely delving into areas never before tested. I don't think we have ever even had a machine with more than 2GB of memory. 18gb is definitely going to stress the system.
Here the issues I think you are running into, it may be better to get them into separate issues for tracking:
1) my best guess is that the act of switching the log file at 1 gig has become stuck behind finishing the checkpoint. I don't
believe there is a design issue that we have to wait for checkpoint to switch. My first guess is that out single background
daemon is stuck doing a checkpoint and can't service the switch request - but I have not checked the code. For these
multi-processor systems a single daemon not doing anything async is probably not going to cut it.
2) The math for largest file number looks like it has a bug somewhere. I don't think we ever really expected a file to grow to
this size, mostly it was there to make sure someone didn't set the log file size to greater than it. A test should be written
and the code fixed to properly handle forcing a switch, or waiting for a switch if you get to this size. My guess is this has
not been tested before. I am not sure how easy such a test will be, other than a stress test like yours - though the real
fix is probably to fix 1 and avoid 2 all together.
3) ASSERT messages weren't very helpful, I'll update them so at least we get the real info out when you run into this.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.0.0
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Trejkaz (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12745751#action_12745751 ]
Trejkaz commented on DERBY-2254:
--------------------------------
We have one user experiencing this issue in production. We don't do any crazy stuff like compressing tables or checkpointing, but we do add lots of rows quickly and I don't know, maybe once the computer gets sufficiently fast, this issue surfaces.
The machine our user are using is a monster with 32GB of RAM, although we allocate less than 2GB for each individual process which each have their own database.
What is the underlying cause here? I/O not being fast enough to update the database so it has to write to the log instead? Is there any way to avoid it at all?
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.1.4
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-2254:
--------------------------------------
Urgency: Normal
Bug behavior facts: [Crash]
Triaged for 10.5.2.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.1.4
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-2254) Assert during log file switch: log
file position exceeded max log file size
Posted by "quartz (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-2254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12555737#action_12555737 ]
quartz commented on DERBY-2254:
-------------------------------
A few details:
-I have this state generated from a linux machine (not OS specific).
-I use the derbynet NetworkServerControl, not the embeded driver.
-I also saw the error while starting up on windows with embeded driver over the copied DB.
-I am on 10.2.2.0.
I deleted the log file and the DB works. Of course I expect data loss but
I wanted to know that only the log file seems affected.
> Assert during log file switch: log file position exceeded max log file size
> ---------------------------------------------------------------------------
>
> Key: DERBY-2254
> URL: https://issues.apache.org/jira/browse/DERBY-2254
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.3.1.4
> Environment: Solaris 10, Java SE 6 build 104
> Reporter: Olav Sandstaa
>
> When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> This seems to occur during a switch to a new log file.
> derby.log contains the following call stack for the background thread:
> Exception trace:
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> 2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
> at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
> at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
> at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
> at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
> at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
> at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
> at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> For my user threads the call stack is similar:
> Database Class Loader started - derby.database.classpath=''
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
> 2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
> org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
> at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
> at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
> at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
> at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
> at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
> at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
> at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
> at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
> at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
> at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
> at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
> at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
> at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
> at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
> at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)
> After this it seems like no user threads are able to connect to the database (not surpricing).
> This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.