Can't create a new db on OS X

• Key: DERBY-1
• Type: Bug
• Status: Closed
• Resolution: Fixed
• Priority: Major
• Assignee: Suresh Thalamati
• Reporter: Tom Santos
• Component/s: Store
• Affects Version/s: 10.0.2.0
• Fix Version/s: 10.1.2.1, 10.2.1.6

Description

This problem does not occur when I use the same jars on Linux.

I am unable to create a new database in ij by using the following command:

connect 'jdbc:derby:testdb;create=true';

I get the following output:

ERROR XJ041: Failed to create database 'testdb', see the next exception for details.
ERROR XBM01: Startup failed due to an exception, see next exception for details.
ERROR XJ001: Java exception: '/Users/tom/dev/java/derby-bin/lib/testdb/log/log1.dat (File exists): java.io.FileNotFoundException'.

All users have write permissions to the directory so it's not getting blocked there. I'm not sure what's going on. I've included the contents of derby.log below. I've also included the result of running sysinfo on my machine below that.

----------------------------------------------------------------
2004-09-24 20:33:53.762 GMT:
 Booting Derby version IBM Corp. - Apache Derby - 10.0.2.0 - (30301): instance c013800d-00ff-3226-5601-00000015bd70
on database directory /Users/tom/dev/java/derby-bin/lib/testdb


2004-09-24 20:33:53.821 GMT:
Shutting down instance c013800d-00ff-3226-5601-00000015bd70
----------------------------------------------------------------
2004-09-24 20:33:53.837 GMT Thread[main,5,main] Cleanup action starting
ERROR XBM01: Startup failed due to an exception, see next exception for details.
        at org.apache.derby.iapi.error.StandardException.newException(StandardException.java)
        at org.apache.derby.iapi.services.monitor.Monitor.exceptionStartingModule(Monitor.java)
        at org.apache.derby.impl.store.raw.log.LogToFile.boot(LogToFile.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.bootLogFactory(BaseDataFileFactory.java)
        at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.setRawStoreFactory(BaseDataFileFactory.java)
        at org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java)
        at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.createPersistentService(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.createPersistentService(Monitor.java)
        at org.apache.derby.impl.jdbc.EmbedConnection.createDatabase(EmbedConnection.java)
        at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java)
        at org.apache.derby.impl.jdbc.EmbedConnection20.<init>(EmbedConnection20.java)
        at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java)
        at org.apache.derby.jdbc.Driver30.getNewEmbedConnection(Driver30.java)
        at org.apache.derby.jdbc.Driver169.connect(Driver169.java)
        at java.sql.DriverManager.getConnection(DriverManager.java:512)
        at java.sql.DriverManager.getConnection(DriverManager.java:140)
        at org.apache.derby.impl.tools.ij.ij.dynamicConnection(ij.java)
        at org.apache.derby.impl.tools.ij.ij.ConnectStatement(ij.java)
        at org.apache.derby.impl.tools.ij.ij.ijStatement(ij.java)
        at org.apache.derby.impl.tools.ij.utilMain.go(utilMain.java)
        at org.apache.derby.impl.tools.ij.Main.go(Main.java)
        at org.apache.derby.impl.tools.ij.Main.mainCore(Main.java)
        at org.apache.derby.impl.tools.ij.Main14.main(Main14.java)
        at org.apache.derby.tools.ij.main(ij.java)
============= begin nested exception, level (1) ===========
java.io.FileNotFoundException: /Users/tom/dev/java/derby-bin/lib/log/log1.dat (File exists)
        at java.io.RandomAccessFile.open(Native Method)
        at java.io.RandomAccessFile.<init>(RandomAccessFile.java:204)
        at org.apache.derby.impl.io.DirRandomAccessFile.<init>(DirRandomAccessFile.java)
        at org.apache.derby.impl.io.DirRandomAccessFile4.<init>(DirRandomAccessFile4.java)
        at org.apache.derby.impl.io.DirFile4.getRandomAccessFile(DirFile4.java)
        at org.apache.derby.impl.store.raw.log.LogToFile.run(LogToFile.java)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.derby.impl.store.raw.log.LogToFile.privRandomAccessFile(LogToFile.java)
        at org.apache.derby.impl.store.raw.log.LogToFile.boot(LogToFile.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.bootLogFactory(BaseDataFileFactory.java)
        at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.setRawStoreFactory(BaseDataFileFactory.java)
        at org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java)
        at org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java)
        at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java)
        at org.apache.derby.impl.services.monitor.BaseMonitor.createPersistentService(BaseMonitor.java)
        at org.apache.derby.iapi.services.monitor.Monitor.createPersistentService(Monitor.java)
        at org.apache.derby.impl.jdbc.EmbedConnection.createDatabase(EmbedConnection.java)
        at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java)
        at org.apache.derby.impl.jdbc.EmbedConnection20.<init>(EmbedConnection20.java)
        at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java)
        at org.apache.derby.jdbc.Driver30.getNewEmbedConnection(Driver30.java)
        at org.apache.derby.jdbc.Driver169.connect(Driver169.java)
        at java.sql.DriverManager.getConnection(DriverManager.java:512)
        at java.sql.DriverManager.getConnection(DriverManager.java:140)
        at org.apache.derby.impl.tools.ij.ij.dynamicConnection(ij.java)
        at org.apache.derby.impl.tools.ij.ij.ConnectStatement(ij.java)
        at org.apache.derby.impl.tools.ij.ij.ijStatement(ij.java)
        at org.apache.derby.impl.tools.ij.utilMain.go(utilMain.java)
        at org.apache.derby.impl.tools.ij.Main.go(Main.java)
        at org.apache.derby.impl.tools.ij.Main.mainCore(Main.java)
        at org.apache.derby.impl.tools.ij.Main14.main(Main14.java)
        at org.apache.derby.tools.ij.main(ij.java)
============= end nested exception, level (1) ===========
Cleanup action completed


------------------ Java Information ------------------
Java Version: 1.4.2_05
Java Vendor: Apple Computer, Inc.
Java home: /System/Library/Frameworks/JavaVM.framework/Versions/1.4.2/Home
Java classpath: /Users/tom/dev/java/derby-bin/lib/derby.jar:/Users/tom/dev/java/derby-bin/lib/derbytools.jar:/Users/tom/dev/java/derby-bin/lib/derbynet.jar:/Users/tom/dev/java/derby-bin/lib/db2jcc.jar:/Users/tom/dev/java/derby-bin/lib/db2jcc_license_c.jar
OS name: Mac OS X
OS architecture: ppc
OS version: 10.3.5
Java user name: tom
Java user home: /Users/tom
Java user dir: /Users/tom/dev/java/derby-bin/lib
--------- Derby Information --------
[/Users/tom/dev/java/derby-bin/lib/derby.jar] 10.0.2.0 - (46005)
[/Users/tom/dev/java/derby-bin/lib/derbytools.jar] 10.0.2.0 - (46005)
[/Users/tom/dev/java/derby-bin/lib/derbynet.jar] 10.0.2.0 - (46005)
[/Users/tom/dev/java/derby-bin/lib/db2jcc.jar] 2.4 - (17)
[/Users/tom/dev/java/derby-bin/lib/db2jcc_license_c.jar] 2.4 - (17)
------------------------------------------------------
----------------- Locale Information -----------------
------------------------------------------------------

Comments

[Joseph Grace]

This issue has been discussed on derby-dev including a patch which works on OSX and (I believe) should work elsewhere as well. The relevant (thread and) post is:

http://nagoya.apache.org/eyebrowse/ReadMsg?listName=[e-mail]&msgNo=233

It actually includes a fix for another (I suspect) bug as well.

The gist of the fix is to change the write mode from "rws" (which causes an issue on OSX) to the less strenuous "rwd". The difference is that "rws" keeps metadata synchronously (as well as data) whereas "rwd" just does the data (and only the metadata _necessary_ to ensure the data is recoverable). IOW, it's quite possible that "rwd" is the preferred mode for a high performance database.

As for why "rws" has issues on OSX, the issue was unresolved as there are ambiguities in what OSX is doing, and what exactly "rws" should do under certain circumstances. The interesting circumstance in this case is that a data file exists yet (presumably?) associated metadata files do not exist, possibly leading to the error. That's my take on it anyway. I have not had time to track it further, but it works with the patch on OSX.

-=-

I'm not sure what the process is to approve or disapprove my proposed patch.

[Jan Hlavatý]

Let me warn you though - we got suspiciously high throughput when using "rwd", so we suspect it may not do what it is supposed to do, and crash recovery may not work as good as expected.

[Tom Santos]

The "rwd" patch got it working for me. Thanks much.

[Suresh Thalamati]

There is a work around for this problem without applying any PATCH.
This problem occurs when "write sync" mechanisms (rws mode) is used to write log. Current system has a flag to disable write sync and use file sync to make sure logs are written to disk on commit.
 
Write sync mode can be disabled by setting "derby.storage.fileSyncTransactionLog=true" in derby.properties. When this property is set to true logging system does file syncs on commits similar to what happens on jvms before jdk142.


My two cents on the patch:
As Jan mentioned before , I also don't believe "rwd" mode is doing sync writes on MAC OS. If syncs does not occur, users can have unrecoverable databases or lost data. Until Apple fixes "rws/rwd" bug.It would be safer for users to use derby.storage.fileSyncTransactionLog or have another PATCH that will identify MAC OS and make logging system use file sync until JVM bug is fixed.

Although using "rwd" may provide better performance on some OS. I don't think it is safe to fix this problem.

Having OS specific checks is not a clean solution, but I can not think of any other alternative way to fix this problem. Any ideas ?


 

[Andrew McIntyre]

FYI, I have reported the "rws/rwd" mode issue to Apple. It does not appear to have been fixed with the recent Java 1.4.2 Update 2 release.

[Daniel John Debrunner]

Samuel Andrew McIntyre wrote:

Here is a copy of the bug report I filed with Apple:
Summary:
java.io.RandomAccessFile in Java 1.4.2 Update 1 does not allow reopening files in "rws" mode if they have just been created. When a file is created with "rw" and then shortly thereafter a new RandomAccessFile object is instantiated for the same file in "rws" mode, the JVM throws a FileNotFoundException (File Exists). "rw" and "rwd" modes do not have this problem. This issue is hit when attempting to create or write to a
database with IBM Cloudscape/Apache Derby 10.0.


The testcase referenced above is Suresh's TestWriteSync.java.

http://nagoya.apache.org/eyebrowse/ReadMsg?listName=[e-mail]&msgNo=232

[mario zanier]

hi,

where do i place this derby.properties file with derby.storage.fileSyncTransactionLog=true on os x, to create databases with bash or DBviz ?

regards,
mario

[Kathy Saunders]

Mario,

derby.properties must be placed in derby.system.home. By default derby.system.home is your current directory when you start Derby. You can read more about how to explicitly set derby.system.home to a directory of your choice in the Tuning Guide at http://incubator.apache.org/derby/manuals/tuning/perf14.html#HDRSII-SETPROP-16827.

[Andrew McIntyre]

The underlying JVM issue has been fixed in Mac OS X 10.4 (Tiger), but remains a problem on Mac OS X 10.3.

[Andrew McIntyre]

There is a regression of DERBY-1 in the J2SE 5.0 Release 1 JVM for Mac OS X 10.4. The issue has been fixed in the JDK 1.4.2 JVM for Mac OS X 10.4, which is the default JVM, but identical errors to those seen on Mac OS X 10.3 with JDK 1.4.2 wiill be encountered with the 5.0 JVM for Mac OS X 10.4.

The problem has NOT been fixed in OS X 10.4 (Tiger), at least not with Java 1.5.0_02; I just tried running Derby on a newly
installed Tiger system with Java 1.5 and get the same problem.

[Barnet Wagman]

Suresh's TestWriteSync test FAILS on Tiger with Java 1.5.0_02

Furthermore, derby.storage.fileSyncTransactionLog=true does not appear to solve
 the problem; I am able to create a database, but not add to it in a subsequent session.

[Andrew McIntyre]

Barnet,

Are you sure you are setting the property derby.storage.fileSyncTransactionLog=true *every* time you start up Derby and connect to the database? You must set this system property every time you start up Derby in order for it to work properly on Mac OS X 10.4 with J2SE 1.5 (JDK 1.5). I am able to create a database and insert data into tables in subsequent sessions so long as I set that system property every time.

FYI, I reported the regression to Apple about a month ago, so they are aware of the problem.

[Barnet Wagman]

Yes, my code is

...
System.setProperty("derby.storage.fileSyncTransactionLog","true");
new org.apache.derby.jdbc.EmbeddedDriver();
con = DriverManager.getConnection(...);
...

and I only have one DriverManager.getConnection(...) call, except for an
explicit shutdown:
       DriverManager.getConnection("jdbc:derby:;shutdown=true");

[Barnet Wagman]

I was wrong, derby.storage.fileSyncTransactionLog=true does fix the problem on Tiger with Java 1.5

[Suresh Thalamati]

I was hoping this issue will go away , but it seems to have appeared again in jdk1.5. Although there is a workaround by
setting derby.storage.fileSyncTransactionLog=true. I think for users who are just tryingout Derby , hitting this problem is very annoying.
Resubmmitting the workaround patch(derby1.diff) for this problem againest main trunk. This patch solves the problem by
Catching the FileNotFoundException then set log write mode to file Sync and then open the log files in plain "rw" mode.

Although it is a vendor spefic fix , I think it will really help users tryingout derby on Mac. It would be great if some one can review the
patch and reconsider it for committing into 10.1 and main, if there are no objections from the community.
 
All tests passed on WIndow Xp.

My vote +1 .
  

[Suresh Thalamati]

Merged this fix into 10.1 client from trunk and ran all functional tests. All tests passes on jdk142/WindowsXP.
I like to see this fix in 10.1 branch , it would be great if some one could commit this into 10.1.

Merge command:
svn merge -r 306822:306963 https://svn.apache.org/repos/asf/db/derby/code/trunk

Thanks
-suresh

[Kathey Marsden]

Changing fixin to 10.1.2 as Andrew indicated he would be merging it to 10.1

[Andrew McIntyre]

Merged fix to 10.1 branch with revision 326300.

[Andrew McIntyre]

This issue has been resolved for over a year with no further movement. Closing.