[daisy] [JIRA] Commented: (DSY-457) Automatic shutdown of Daisy repository service does not clean up write lock (and prevents startup)

Bruno Dumon (JIRA) issues at cocoondev.org
Thu Jun 7 05:33:46 CDT 2007


    [ http://issues.cocoondev.org//browse/DSY-457?page=comments#action_13207 ] 

Bruno Dumon commented on DSY-457:
---------------------------------

I have looked into this problem and found a solution.

First some background:

Windows does shut down the services in correct order, thus first the repository and then MySQL.

However, Daisy can't connect to MySQL anymore since the network services are first shut down, the solution is hence to add a dependency on the "Network connections" service. See below for how this can be done.

However, while the inability to connect to MySQL causes some errors in the logs, the reason the shutdown fails seems to be because of long timeouts in the closing of JMS sessions (I think), also due to lack of the network services.

Besides this, I've also found a race condition that could sometimes cause an NPE in the shutdown of the JmsClient component. I'm also going to adjust the fulltext index component so that it automatically removes the indexstore write.lock on startup if it is present, combined with printing an error in the log and a warning to System.err. This is just for convenience though, and doesn't solve anything.



Now to add the dependency:

in the following file:

<daisyrepodata dir>/service/daisy-repository-server-service.conf

add the following line (preferably after the already present MySQL dependency):

wrapper.ntservice.dependency.2=Netman

And then uninstall/install the daisy service using the scripts in <daisyrepodata dir>/service


> Automatic shutdown of Daisy repository service does not clean up write lock (and prevents startup)
> --------------------------------------------------------------------------------------------------
>
>          Key: DSY-457
>          URL: http://issues.cocoondev.org//browse/DSY-457
>      Project: Daisy
>         Type: Bug
>   Components: Repository
>     Versions: 2.0.1
>  Environment: Windows XP SP2
>     Reporter: Geoffrey De Smet
>      Fix For: 2.1

>
> When I directly call the repo service shutdown, it cleans up the write lock.
> When windows calls it when I turn off my machine, it doesn't clean up write lock (see the log below).
> This prevents the repo from starting up when I turn on my machine.
> And windows's services properties show that the repo is dependend on MySQL, so it should shutdown before mysql.
> Here's the service.log:
> INFO   | jvm 1    | 2007/04/20 12:32:19 | org.jbpm.persistence.JbpmPersistenceException: hibernate close session failed
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:240)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.svc.Services.close(Services.java:222)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.JbpmContext.close(JbpmContext.java:139)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.job.executor.JobExecutorThread.acquireJobs(JobExecutorThread.java:141)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:56)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.job.executor.DaisyJobExecutorThread.run(DaisyJobExecutorThread.java:48)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | Caused by: org.hibernate.exception.GenericJDBCException: Cannot release connection
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:449)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:400)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:287)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:221)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.JDBCContext.connectionCleanedUp(JDBCContext.java:97)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.cleanup(ConnectionManager.java:388)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.close(ConnectionManager.java:318)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.impl.SessionImpl.close(SessionImpl.java:298)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.persistence.db.DbPersistenceService.closeSession(DbPersistenceService.java:310)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:237)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	... 5 more
> INFO   | jvm 1    | 2007/04/20 12:32:24 | Caused by: java.sql.SQLException: Already closed.
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:66)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.outerj.daisy.workflow.serverimpl.DaisyConnectionProvider.closeConnection(DaisyConnectionProvider.java:49)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
> INFO   | jvm 1    | 2007/04/20 12:32:24 | 	... 14 more
> ERROR  | wrapper  | 2007/04/20 12:32:26 | Shutdown failed: Timed out waiting for the JVM to terminate.
> ERROR  | wrapper  | 2007/04/20 12:32:26 | JVM did not exit on request, terminated
> STATUS | wrapper  | 2007/04/20 12:32:27 | <-- Wrapper Stopped
> STATUS | wrapper  | 2007/04/23 08:26:08 | --> Wrapper Started as Service
> STATUS | wrapper  | 2007/04/23 08:26:08 | Launching a JVM...
> INFO   | jvm 1    | 2007/04/23 08:26:09 | Wrapper (Version 3.2.3) http://wrapper.tanukisoftware.org
> INFO   | jvm 1    | 2007/04/23 08:26:09 |   Copyright 1999-2006 Tanuki Software, Inc.  All Rights Reserved.
> INFO   | jvm 1    | 2007/04/23 08:26:09 | 
> INFO   | jvm 1    | 2007/04/23 08:26:15 | ---- exception report ----------------------------------------------------------
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Exception: org.apache.avalon.merlin.KernelException
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Message: Kernel startup failure.
> INFO   | jvm 1    | 2007/04/23 08:26:15 | ---- cause ---------------------------------------------------------------------
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Exception: org.apache.avalon.merlin.KernelException
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Message: Cannot deploy application.
> INFO   | jvm 1    | 2007/04/23 08:26:15 | ---- cause ---------------------------------------------------------------------
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Exception: org.apache.avalon.activation.LifecycleException
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Message: Unable to create a new component instance in appliance [/daisy/repository/fullTextIndex] due to a component deployment failure.
> INFO   | jvm 1    | 2007/04/23 08:26:15 | ---- cause ---------------------------------------------------------------------
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Exception: java.io.IOException
> INFO   | jvm 1    | 2007/04/23 08:26:15 | Message: Lock obtain timed out: SimpleFSLock at C:\app\cms\daisy-2.0.1\data\indexstore\write.lock
> INFO   | jvm 1    | 2007/04/23 08:26:15 | ---- stack trace ---------------------------------------------------------------
> INFO   | jvm 1    | 2007/04/23 08:26:15 | java.io.IOException: Lock obtain timed out: SimpleFSLock at C:\app\cms\daisy-2.0.1\data\indexstore\write.lock
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.lucene.store.Lock.obtain(Lock.java:69)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.lucene.index.IndexWriter.init(IndexWriter.java:367)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.lucene.index.IndexWriter.init(IndexWriter.java:352)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:314)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.outerj.daisy.ftindex.FullTextIndexImpl.constructIndexWriter(FullTextIndexImpl.java:307)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.outerj.daisy.ftindex.FullTextIndexImpl.updateWriter(FullTextIndexImpl.java:303)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.outerj.daisy.ftindex.FullTextIndexImpl.initialize(FullTextIndexImpl.java:109)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.framework.container.ContainerUtil.initialize(ContainerUtil.java:244)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.DefaultComponentFactory.incarnation(DefaultComponentFactory.java:402)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.DefaultComponentFactory.incarnate(DefaultComponentFactory.java:130)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.SingletonLifestyleManager.refreshReference(SingletonLifestyleManager.java:144)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.SingletonLifestyleManager.commission(SingletonLifestyleManager.java:60)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.DefaultAppliance.commission(DefaultAppliance.java:94)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.activation.impl.DefaultRuntime.commission(DefaultRuntime.java:86)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.composition.model.impl.DefaultSystemContext.commission(DefaultSystemContext.java:362)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.composition.model.impl.DefaultDeploymentModel.commission(DefaultDeploymentModel.java:122)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | org.apache.avalon.composition.model.impl.Commissioner.run(Commissioner.java:185)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | java.lang.Thread.run(Unknown Source)
> INFO   | jvm 1    | 2007/04/23 08:26:15 | --------------------------------------------------------------------------------

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://issues.cocoondev.org//secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira



More information about the daisy mailing list