[DuraSpace JIRA] (FCREPO-998) RI Module fails to start if log level is set to DEBUG

11 views

Skip to first unread message

Stephen Bayliss (Created) (DuraSpace JIRA)

unread,

Sep 15, 2011, 3:21:04 AM9/15/11

to fcrepo-...@googlegroups.com

RI Module fails to start if log level is set to DEBUG
-----------------------------------------------------

Key: FCREPO-998
URL: https://jira.duraspace.org/browse/FCREPO-998
Project: Fedora Repository Project
Issue Type: Bug
Components: Fedora
Affects Versions: Fedora 3.5
Environment: RI enabled, FeSL disabled or enabled, XACML disabled (not tested with it enabled)
Reporter: Stephen Bayliss
Priority: Major

If the log level is set to DEBUG, the resource index module fails to start. Also once the server has started in this state it fails to shutdown cleanly.

Exceptions reported:

Tomcat log:

**************************
** FEDORA STARTUP ERROR **
**************************

Fedora startup failed
org.fcrepo.server.errors.ModuleInitializationException: Error initializing
RI
at
org.fcrepo.server.resourceIndex.ResourceIndexModule.postInitModule(Re
sourceIndexModule.java:127)
at org.fcrepo.server.Server.<init>(Server.java:644)
at org.fcrepo.server.BasicServer.<init>(BasicServer.java:41)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)

at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstruct
orAccessorImpl.java:39)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingC
onstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at org.fcrepo.server.Server.getInstance(Server.java:1239)
at
org.fcrepo.server.ServerController.init(ServerController.java:403)
at javax.servlet.GenericServlet.init(GenericServlet.java:212)
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.
java:1173)
at
org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:99
3)
at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContex
t.java:4350)
at
org.apache.catalina.core.StandardContext.start(StandardContext.java:4
659)
at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase
.java:791)
at
org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:77
1)
at
org.apache.catalina.core.StandardHost.addChild(StandardHost.java:546)

at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.ja
va:637)
at
org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.j
ava:563)
at
org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498
)
at
org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java
:321)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(Lifecycl
eSupport.java:119)
at
org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)

at
org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
at
org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)

at
org.apache.catalina.core.StandardEngine.start(StandardEngine.java:445
)
at
org.apache.catalina.core.StandardService.start(StandardService.java:5
19)
at
org.apache.catalina.core.StandardServer.start(StandardServer.java:710
)
at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
sorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: java.lang.UnsupportedOperationException: This MulgaraConnector is
rea
d-only!
at
org.trippi.impl.mulgara.MulgaraConnector.getWriter(MulgaraConnector.j
ava:104)
at
org.fcrepo.server.resourceIndex.ResourceIndexImpl.<init>(ResourceInde
xImpl.java:74)
at
org.fcrepo.server.resourceIndex.ResourceIndexModule.postInitModule(Re
sourceIndexModule.java:120)
... 35 more

Fedora log:

DEBUG 2011-09-14 18:11:41.036 [main] (DefaultListableBeanFactory) Finished
creating instance of bean 'org.fcrepo.server.resourceIndex.TripleGenerator'
DEBUG 2011-09-14 18:11:41.067 [main] (SessionFactoryFinder) Attempting to
connect via RMI
DEBUG 2011-09-14 18:11:42.177 [main] (SessionFactoryFinder) Failed to
connect via RMI
javax.naming.ServiceUnavailableException: null
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:101)
[na:1.6.0_17]
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:107)
[na:1.6.0_17]
at javax.naming.InitialContext.lookup(InitialContext.java:392)
[na:1.6.0_17]
at
org.mulgara.server.driver.SessionFactoryFinder.newSessionFactory(SessionFact
oryFinder.java:147) [mulgara-core-2.1.4.jar:na]
at
org.trippi.impl.mulgara.MulgaraSessionFactory.<init>(MulgaraSessionFactory.j
ava:75) [trippi-mulgara-1.5.4.jar:na]
at org.trippi.impl.mulgara.MulgaraConnector.open(MulgaraConnector.java:242)
[trippi-mulgara-1.5.4.jar:na]
at
org.trippi.impl.mulgara.MulgaraConnector.getWriter(MulgaraConnector.java:97)
[trippi-mulgara-1.5.4.jar:na]
at
org.fcrepo.server.resourceIndex.ResourceIndexImpl.<init>(ResourceIndexImpl.j
ava:74) [fcrepo-server-3.5.jar:na]
at
org.fcrepo.server.resourceIndex.ResourceIndexModule.postInitModule(ResourceI
ndexModule.java:120) [fcrepo-server-3.5.jar:na]
at org.fcrepo.server.Server.<init>(Server.java:644)
[fcrepo-server-3.5.jar:na]
at org.fcrepo.server.BasicServer.<init>(BasicServer.java:41)
[fcrepo-server-3.5.jar:na]
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[na:1.6.0_17]
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
sorImpl.java:39) [na:1.6.0_17]
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
torAccessorImpl.java:27) [na:1.6.0_17]
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
[na:1.6.0_17]
at org.fcrepo.server.Server.getInstance(Server.java:1239)
[fcrepo-server-3.5.jar:na]
at org.fcrepo.server.ServerController.init(ServerController.java:403)
[fcrepo-server-3.5.jar:na]
at javax.servlet.GenericServlet.init(GenericServlet.java:212)
[servlet-api.jar:2.5.MR2]
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:11
73) [catalina.jar:6.0.29]
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:
4350) [catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardContext.start(StandardContext.java:4659)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:7
91) [catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:546)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563
) [catalina.jar:6.0.29]
at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
[catalina.jar:6.0.29]
at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
[catalina.jar:6.0.29]
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSuppor
t.java:119) [catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
[catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:445)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardService.start(StandardService.java:519)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
[catalina.jar:6.0.29]
at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
[catalina.jar:6.0.29]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[na:1.6.0_17]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39
) [na:1.6.0_17]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25) [na:1.6.0_17]
at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_17]
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
[bootstrap.jar:6.0.29]
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
[bootstrap.jar:6.0.29]
Caused by: java.rmi.ConnectException: Connection refused to host: localhost;
nested exception is:
java.net.ConnectException: Connection refused: connect
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:601)
[na:1.6.0_17]
at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:198)
[na:1.6.0_17]
at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:184)
[na:1.6.0_17]
at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:322) [na:1.6.0_17]
at sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source) [na:1.6.0_17]
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:97)
[na:1.6.0_17]
... 43 common frames omitted
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method) [na:1.6.0_17]
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
[na:1.6.0_17]
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
[na:1.6.0_17]
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) [na:1.6.0_17]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) [na:1.6.0_17]
at java.net.Socket.connect(Socket.java:525) [na:1.6.0_17]
at java.net.Socket.connect(Socket.java:475) [na:1.6.0_17]
at java.net.Socket.<init>(Socket.java:372) [na:1.6.0_17]
at java.net.Socket.<init>(Socket.java:186) [na:1.6.0_17]
at
sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(RMIDirectSocketF
actory.java:22) [na:1.6.0_17]
at
sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(RMIMasterSocketF
actory.java:128) [na:1.6.0_17]
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:595)
[na:1.6.0_17]
... 48 common frames omitted
DEBUG 2011-09-14 18:11:42.239 [main] (SessionFactoryFinder) Attempting to
fallback to local
javax.naming.ServiceUnavailableException: null
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:101)
[na:1.6.0_17]
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:107)
[na:1.6.0_17]
at javax.naming.InitialContext.lookup(InitialContext.java:392)
[na:1.6.0_17]
at
org.mulgara.server.driver.SessionFactoryFinder.newSessionFactory(SessionFact
oryFinder.java:147) [mulgara-core-2.1.4.jar:na]
at
org.trippi.impl.mulgara.MulgaraSessionFactory.<init>(MulgaraSessionFactory.j
ava:75) [trippi-mulgara-1.5.4.jar:na]
at org.trippi.impl.mulgara.MulgaraConnector.open(MulgaraConnector.java:242)
[trippi-mulgara-1.5.4.jar:na]
at
org.trippi.impl.mulgara.MulgaraConnector.getWriter(MulgaraConnector.java:97)
[trippi-mulgara-1.5.4.jar:na]
at
org.fcrepo.server.resourceIndex.ResourceIndexImpl.<init>(ResourceIndexImpl.j
ava:74) [fcrepo-server-3.5.jar:na]
at
org.fcrepo.server.resourceIndex.ResourceIndexModule.postInitModule(ResourceI
ndexModule.java:120) [fcrepo-server-3.5.jar:na]
at org.fcrepo.server.Server.<init>(Server.java:644)
[fcrepo-server-3.5.jar:na]
at org.fcrepo.server.BasicServer.<init>(BasicServer.java:41)
[fcrepo-server-3.5.jar:na]
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[na:1.6.0_17]
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
sorImpl.java:39) [na:1.6.0_17]
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
torAccessorImpl.java:27) [na:1.6.0_17]
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
[na:1.6.0_17]
at org.fcrepo.server.Server.getInstance(Server.java:1239)
[fcrepo-server-3.5.jar:na]
at org.fcrepo.server.ServerController.init(ServerController.java:403)
[fcrepo-server-3.5.jar:na]
at javax.servlet.GenericServlet.init(GenericServlet.java:212)
[servlet-api.jar:2.5.MR2]
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:11
73) [catalina.jar:6.0.29]
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:
4350) [catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardContext.start(StandardContext.java:4659)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:7
91) [catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:546)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563
) [catalina.jar:6.0.29]
at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
[catalina.jar:6.0.29]
at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
[catalina.jar:6.0.29]
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
[catalina.jar:6.0.29]
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSuppor
t.java:119) [catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
[catalina.jar:6.0.29]
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:445)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardService.start(StandardService.java:519)
[catalina.jar:6.0.29]
at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
[catalina.jar:6.0.29]
at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
[catalina.jar:6.0.29]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[na:1.6.0_17]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39
) [na:1.6.0_17]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25) [na:1.6.0_17]
at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_17]
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
[bootstrap.jar:6.0.29]
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
[bootstrap.jar:6.0.29]
Caused by: java.rmi.ConnectException: Connection refused to host: localhost;
nested exception is:
java.net.ConnectException: Connection refused: connect
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:601)
[na:1.6.0_17]
at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:198)
[na:1.6.0_17]
at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:184)
[na:1.6.0_17]
at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:322) [na:1.6.0_17]
at sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source) [na:1.6.0_17]
at
com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:97)
[na:1.6.0_17]
... 43 common frames omitted
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method) [na:1.6.0_17]
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
[na:1.6.0_17]
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
[na:1.6.0_17]
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) [na:1.6.0_17]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) [na:1.6.0_17]
at java.net.Socket.connect(Socket.java:525) [na:1.6.0_17]
at java.net.Socket.connect(Socket.java:475) [na:1.6.0_17]
at java.net.Socket.<init>(Socket.java:372) [na:1.6.0_17]
at java.net.Socket.<init>(Socket.java:186) [na:1.6.0_17]
at
sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(RMIDirectSocketF
actory.java:22) [na:1.6.0_17]
at
sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(RMIMasterSocketF
actory.java:128) [na:1.6.0_17]
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:595)
[na:1.6.0_17]
... 48 common frames omitted

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://jira.duraspace.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

Chris Wilper (Updated) (DuraSpace JIRA)

unread,

Nov 1, 2011, 11:24:03 AM11/1/11

to fcrepo-...@googlegroups.com

[ https://jira.duraspace.org/browse/FCREPO-998?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Chris Wilper updated FCREPO-998:
--------------------------------

Status: Open (was: Received)

Chris Wilper (Updated) (DuraSpace JIRA)

unread,

Nov 1, 2011, 11:24:04 AM11/1/11

to fcrepo-...@googlegroups.com

[ https://jira.duraspace.org/browse/FCREPO-998?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Chris Wilper updated FCREPO-998:
--------------------------------

Fix Version/s: Fedora 3.6

> RI Module fails to start if log level is set to DEBUG
> -----------------------------------------------------
>
> Key: FCREPO-998
> URL: https://jira.duraspace.org/browse/FCREPO-998
> Project: Fedora Repository Project
> Issue Type: Bug
> Components: Fedora
> Affects Versions: Fedora 3.5
> Environment: RI enabled, FeSL disabled or enabled, XACML disabled (not tested with it enabled)
> Reporter: Stephen Bayliss
> Priority: Major