Petals ESB Container

Error message "Cannot open connection" thrown by the registry when starting Petals

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 3.1.3
  • Fix Version/s: 3.1.4, 4.1.0
  • Component/s: Registry
  • Security Level: Public
  • Description:
    Hide

    In few case, I have the following traces loggued:

    [Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,474 Cannot open connection
    [Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,490 Cannot open connection

    when starting Petals.

    The problem does not occur at each Petals start.

    When Petals is started, the registry runs successfully, endpoints can be registered.

    Show
    In few case, I have the following traces loggued:
    [Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,474 Cannot open connection
    [Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,490 Cannot open connection
    when starting Petals. The problem does not occur at each Petals start. When Petals is started, the registry runs successfully, endpoints can be registered.
  • Environment:
    Windows XP, JDK 6,
    A component using a JDBC connection to PostgreSQL is installed

Activity

Hide
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 10:40:33 +0200 - edited

The original exception should be forwarded to be printed with the error message.

After to have added stacktrace print into the source code, the root cause is:

PEtALS ESB is starting...
[Petals.Communication.RMIConnectorImpl]-INFO 2011-08-31 10:23:33,974 JMX RMI server started at : service:jmx:rmi:///jndi/rmi://localhost:7700/jmxRmiConnector
org.hibernate.exception.JDBCConnectionException: Cannot open connection
        at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:97)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
        at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
        at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
        at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
        at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
        at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.deletePath(EndpointDAO.java:331)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.delete(EndpointDAO.java:312)
        at org.ow2.petals.registry.core.repository.jdbc.JDBCRepository.doDelete(JDBCRepository.java:84)
        at org.ow2.petals.registry.core.repository.AbstractRepository.delete(AbstractRepository.java:159)
        at org.ow2.petals.registry.core.AbstractLocalRegistry.doDelete(AbstractLocalRegistry.java:453)
        at org.ow2.petals.registry.core.AbstractRegistry.delete(AbstractRegistry.java:60)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.cleanData(DistributedEndpointRegistryImpl.java:302)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.start(DistributedEndpointRegistryImpl.java:124)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.startFc(DistributedEndpointRegistryImpl.java)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcContentState(BasicControllerMixin.java:8128)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcStarted(BasicControllerMixin.java:8068)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.setFcStarted(INTERFACE[LifeCycleCoordinator])
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc$$0(BasicControllerMixin.java:4097)
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc(BasicControllerMixin.java:5095)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.startFc(INTERFACE[LifeCycleCoordinator])
        at org.ow2.petals.kernel.server.FractalHelper.startComponent(FractalHelper.java:354)
        at org.ow2.petals.kernel.server.PetalsServerImpl.startPetalsComposite(PetalsServerImpl.java:459)
        at org.ow2.petals.kernel.server.PetalsServerImpl.start(PetalsServerImpl.java:176)
        at org.ow2.petals.launcher.AbstractLauncher.start(AbstractLauncher.java:190)
        at org.ow2.petals.launcher.AbstractLauncher.launch(AbstractLauncher.java:147)
        at org.ow2.petals.distribution.platform.Main.main(Main.java:42)
Caused by: java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@b33e5dbe[file =C:\petals-platform-3.1.3-SNAPSHOT-1\work\registry\workspace\Registry@PEtALSESB-0\repository\registry-database01.lck, exists=true, locked=false, valid=false, fl =null]: java.lang.Exception: checkHeartbeat(): lock file [C:\petals-platform-3.1.3-SNAPSHOT-1\work\registry\workspace\Registry@PEtALSESB-0\repository\registry-database01.lck] is presumably locked by another process.
        at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
        at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
        at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
        at org.hsqldb.jdbcDriver.connect(Unknown Source)
        at java.sql.DriverManager.getConnection(DriverManager.java:582)
        at java.sql.DriverManager.getConnection(DriverManager.java:154)
        at org.hibernate.connection.DriverManagerConnectionProvider.getConnection(DriverManagerConnectionProvider.java:133)
        at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
        ... 25 more
org.ow2.petals.registry.core.repository.dao.DAOException: Cannot open connection
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.deletePath(EndpointDAO.java:348)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.delete(EndpointDAO.java:312)
        at org.ow2.petals.registry.core.repository.jdbc.JDBCRepository.doDelete(JDBCRepository.java:84)
        at org.ow2.petals.registry.core.repository.AbstractRepository.delete(AbstractRepository.java:159)
        at org.ow2.petals.registry.core.AbstractLocalRegistry.doDelete(AbstractLocalRegistry.java:453)
        at org.ow2.petals.registry.core.AbstractRegistry.delete(AbstractRegistry.java:60)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.cleanData(DistributedEndpointRegistryImpl.java:302)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.start(DistributedEndpointRegistryImpl.java:124)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.startFc(DistributedEndpointRegistryImpl.java)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcContentState(BasicControllerMixin.java:8128)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcStarted(BasicControllerMixin.java:8068)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.setFcStarted(INTERFACE[LifeCycleCoordinator])
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc$$0(BasicControllerMixin.java:4097)
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc(BasicControllerMixin.java:5095)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.startFc(INTERFACE[LifeCycleCoordinator])
        at org.ow2.petals.kernel.server.FractalHelper.startComponent(FractalHelper.java:354)
        at org.ow2.petals.kernel.server.PetalsServerImpl.startPetalsComposite(PetalsServerImpl.java:459)
        at org.ow2.petals.kernel.server.PetalsServerImpl.start(PetalsServerImpl.java:176)
        at org.ow2.petals.launcher.AbstractLauncher.start(AbstractLauncher.java:190)
        at org.ow2.petals.launcher.AbstractLauncher.launch(AbstractLauncher.java:147)
        at org.ow2.petals.distribution.platform.Main.main(Main.java:42)
[Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,474 Cannot open connection

A Google's search result is: http://blog.xebia.com/2009/03/hsqldb-database-already-in-use-by-another-process-exceptions-on-linux

Installing a simple Grails application in Tomcat on Linux should really have been the most straightforward of tasks. Instead, I spent a progressively more frustrating morning chasing down a "helpful" feature of HSQLDB that was causing the startup to fail with

org.hsqldb.HsqlException: The database is already in use by another process:
org.hsqldb.persist.NIOLockFile@6b67bdbe[file =/myDb.lck, exists=true, locked=false, valid=false,
fl=null]

exceptions. To save others from a similar waste of time, here’s the cause and a workaround:

Cause

Between versions 1.7.2. and 1.8.0.10., HSQLDB attempts to lock the files for file-based DBs in order to "[protect] the user from running the process twice with the same files and corrupting his data", apparently. Unfortunately, if your DB files reside on NFS, which doesn’t support these locks, HSQLDB will blow up with the above exception.

It seems that there have been enough problems with this that HSQLDB has reverted to not using locks by default in 1.8.0.10., although this may be changed again in future versions, it seems.

Workaround(s)

  • Move your DB files to a non-NFS location
  • Upgrade to version 1.8.0.10. (or a pre-1.7.2. version)
  • Use a mem rather than a file DB

The details are described in this thread from the HSQLDB forums.

From what is mentioned there, it would seem to be possible to disable file locking somehow. I tried hsqldb.nio_data_file=false, but that doesn’t seem to do the trick. If anyone finds out how to do this please add a comment!

Show
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 10:40:33 +0200 - edited The original exception should be forwarded to be printed with the error message. After to have added stacktrace print into the source code, the root cause is:
PEtALS ESB is starting...
[Petals.Communication.RMIConnectorImpl]-INFO 2011-08-31 10:23:33,974 JMX RMI server started at : service:jmx:rmi:///jndi/rmi://localhost:7700/jmxRmiConnector
org.hibernate.exception.JDBCConnectionException: Cannot open connection
        at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:97)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
        at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
        at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
        at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
        at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
        at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.deletePath(EndpointDAO.java:331)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.delete(EndpointDAO.java:312)
        at org.ow2.petals.registry.core.repository.jdbc.JDBCRepository.doDelete(JDBCRepository.java:84)
        at org.ow2.petals.registry.core.repository.AbstractRepository.delete(AbstractRepository.java:159)
        at org.ow2.petals.registry.core.AbstractLocalRegistry.doDelete(AbstractLocalRegistry.java:453)
        at org.ow2.petals.registry.core.AbstractRegistry.delete(AbstractRegistry.java:60)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.cleanData(DistributedEndpointRegistryImpl.java:302)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.start(DistributedEndpointRegistryImpl.java:124)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.startFc(DistributedEndpointRegistryImpl.java)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcContentState(BasicControllerMixin.java:8128)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcStarted(BasicControllerMixin.java:8068)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.setFcStarted(INTERFACE[LifeCycleCoordinator])
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc$$0(BasicControllerMixin.java:4097)
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc(BasicControllerMixin.java:5095)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.startFc(INTERFACE[LifeCycleCoordinator])
        at org.ow2.petals.kernel.server.FractalHelper.startComponent(FractalHelper.java:354)
        at org.ow2.petals.kernel.server.PetalsServerImpl.startPetalsComposite(PetalsServerImpl.java:459)
        at org.ow2.petals.kernel.server.PetalsServerImpl.start(PetalsServerImpl.java:176)
        at org.ow2.petals.launcher.AbstractLauncher.start(AbstractLauncher.java:190)
        at org.ow2.petals.launcher.AbstractLauncher.launch(AbstractLauncher.java:147)
        at org.ow2.petals.distribution.platform.Main.main(Main.java:42)
Caused by: java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@b33e5dbe[file =C:\petals-platform-3.1.3-SNAPSHOT-1\work\registry\workspace\Registry@PEtALSESB-0\repository\registry-database01.lck, exists=true, locked=false, valid=false, fl =null]: java.lang.Exception: checkHeartbeat(): lock file [C:\petals-platform-3.1.3-SNAPSHOT-1\work\registry\workspace\Registry@PEtALSESB-0\repository\registry-database01.lck] is presumably locked by another process.
        at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
        at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
        at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
        at org.hsqldb.jdbcDriver.connect(Unknown Source)
        at java.sql.DriverManager.getConnection(DriverManager.java:582)
        at java.sql.DriverManager.getConnection(DriverManager.java:154)
        at org.hibernate.connection.DriverManagerConnectionProvider.getConnection(DriverManagerConnectionProvider.java:133)
        at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
        ... 25 more
org.ow2.petals.registry.core.repository.dao.DAOException: Cannot open connection
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.deletePath(EndpointDAO.java:348)
        at org.ow2.petals.registry.core.repository.dao.EndpointDAO.delete(EndpointDAO.java:312)
        at org.ow2.petals.registry.core.repository.jdbc.JDBCRepository.doDelete(JDBCRepository.java:84)
        at org.ow2.petals.registry.core.repository.AbstractRepository.delete(AbstractRepository.java:159)
        at org.ow2.petals.registry.core.AbstractLocalRegistry.doDelete(AbstractLocalRegistry.java:453)
        at org.ow2.petals.registry.core.AbstractRegistry.delete(AbstractRegistry.java:60)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.cleanData(DistributedEndpointRegistryImpl.java:302)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.start(DistributedEndpointRegistryImpl.java:124)
        at org.ow2.petals.jbi.messaging.registry.DistributedEndpointRegistryImpl.startFc(DistributedEndpointRegistryImpl.java)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcContentState(BasicControllerMixin.java:8128)
        at org.objectweb.fractal.julia.generated.Cbd2013d7_0.setFcStarted(BasicControllerMixin.java:8068)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.setFcStarted(INTERFACE[LifeCycleCoordinator])
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc$$0(BasicControllerMixin.java:4097)
        at org.objectweb.fractal.julia.generated.C4eddf8e0_0.startFc(BasicControllerMixin.java:5095)
        at org.objectweb.fractal.julia.generated.C18c4c884_0.startFc(INTERFACE[LifeCycleCoordinator])
        at org.ow2.petals.kernel.server.FractalHelper.startComponent(FractalHelper.java:354)
        at org.ow2.petals.kernel.server.PetalsServerImpl.startPetalsComposite(PetalsServerImpl.java:459)
        at org.ow2.petals.kernel.server.PetalsServerImpl.start(PetalsServerImpl.java:176)
        at org.ow2.petals.launcher.AbstractLauncher.start(AbstractLauncher.java:190)
        at org.ow2.petals.launcher.AbstractLauncher.launch(AbstractLauncher.java:147)
        at org.ow2.petals.distribution.platform.Main.main(Main.java:42)
[Petals.JBI-Messaging.EndpointRegistryImpl]-SEVERE 2011-08-31 10:23:35,474 Cannot open connection
A Google's search result is: http://blog.xebia.com/2009/03/hsqldb-database-already-in-use-by-another-process-exceptions-on-linux
Installing a simple Grails application in Tomcat on Linux should really have been the most straightforward of tasks. Instead, I spent a progressively more frustrating morning chasing down a "helpful" feature of HSQLDB that was causing the startup to fail with org.hsqldb.HsqlException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@6b67bdbe[file =/myDb.lck, exists=true, locked=false, valid=false, fl=null] exceptions. To save others from a similar waste of time, here’s the cause and a workaround: Cause Between versions 1.7.2. and 1.8.0.10., HSQLDB attempts to lock the files for file-based DBs in order to "[protect] the user from running the process twice with the same files and corrupting his data", apparently. Unfortunately, if your DB files reside on NFS, which doesn’t support these locks, HSQLDB will blow up with the above exception. It seems that there have been enough problems with this that HSQLDB has reverted to not using locks by default in 1.8.0.10., although this may be changed again in future versions, it seems. Workaround(s)
  • Move your DB files to a non-NFS location
  • Upgrade to version 1.8.0.10. (or a pre-1.7.2. version)
  • Use a mem rather than a file DB
The details are described in this thread from the HSQLDB forums. From what is mentioned there, it would seem to be possible to disable file locking somehow. I tried hsqldb.nio_data_file=false, but that doesn’t seem to do the trick. If anyone finds out how to do this please add a comment!
Hide
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 11:38:03 +0200

Using the HSQLDB Driver 1.8.0.10 seems to fix the problem.

Show
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 11:38:03 +0200 Using the HSQLDB Driver 1.8.0.10 seems to fix the problem.
Hide
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 14:25:20 +0200

Fixed in branch petals-enterprise-3.1.x: /petals/container/petals-registry-core

Show
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 14:25:20 +0200 Fixed in branch petals-enterprise-3.1.x: /petals/container/petals-registry-core
Hide
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 14:25:28 +0200

To merge in trunk

Show
Christophe DENEUX added a comment - Wed, 31 Aug 2011 - 14:25:28 +0200 To merge in trunk
Hide
Christophe DENEUX added a comment - Wed, 14 Mar 2012 - 10:44:28 +0100

Merged in trunk

Show
Christophe DENEUX added a comment - Wed, 14 Mar 2012 - 10:44:28 +0100 Merged in trunk

People

Dates

  • Created:
    Wed, 31 Aug 2011 - 10:32:10 +0200
    Updated:
    Wed, 14 Mar 2012 - 10:44:54 +0100
    Resolved:
    Wed, 14 Mar 2012 - 10:44:28 +0100