[JIRA] Commented: (SC-178) IdP fails to start when AttributeFilterEngine uses FileBackedHttpResource and the remote resource is unavailable, but a (usable) backup file is present
Brent Putman (JIRA)
noreply at shibboleth.net
Wed Sep 26 18:24:21 EDT 2012
[ https://issues.shibboleth.net/jira/browse/SC-178?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14416#comment-14416 ]
Brent Putman commented on SC-178:
---------------------------------
I fixed the typos in FileBackedHttpResource.java.
Given the current architecture of the class, we can't really suppress the second log message. The methods are completely distinct operations and so there's no "memory" of what the previous method returned. So the safest thing is for each to emit their own message.
There is a slightly more serious issue implied here - really with all the impls of the Resource interface - in that the result of a series of calls to exists(), getInputStream() and getLastModifiedTime() are not necessarily really consistent amongst themselves, given that the underlying resource can change between the calls. And for example with the file-backed HTTP one, one call might operate against the actual HTTP resource, and the next against the backing file, and so on.
We could probably fix this with some sort of caching redesign of the impls, but need to give some thought to whether it's really worth the effort.
I'm going to resolve this issue since it seems like the original issues have been addressed.
> IdP fails to start when AttributeFilterEngine uses FileBackedHttpResource and the remote resource is unavailable, but a (usable) backup file is present
> -------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: SC-178
> URL: https://issues.shibboleth.net/jira/browse/SC-178
> Project: Shibboleth Common - Java
> Issue Type: Bug
> Components: Configuration
> Affects Versions: 1.3.5
> Reporter: Kaspar Brand
> Assignee: Chad La Joie
>
> When used for a ConfigurationResource within the AttributeFilterEngine service, the FileBackedHttpResource doesn't seem to work when the IdP starts up - or at least not in the way I would expect it to (https://wiki.shibboleth.net/confluence/display/SHIB2/IdPConfigResource#IdPConfigResource-FilebackedHTTPResource says: "The backup copy is used if the remote copy cannot be reached (assuming an initial copy was successfully fetched)").
> When configuring a FilesystemResource for the AttributeFilterEngine like this -
> <srv:Service id="shibboleth.AttributeFilterEngine" xsi:type="attribute-afp:ShibbolethAttributeFilteringEngine">
> <srv:ConfigurationResource xsi:type="resource:FilesystemResource" file="/opt/shibboleth-idp/conf/attribute-filter.xml"/>
> </srv:Service>
> ... and putting a valid config under /opt/shibboleth-idp/conf/attribute-filter.xml, everything is fine with the IdP:
> 2012-04-17 13:29:28,013 - DEBUG [edu.internet2.middleware.shibboleth.common.config.BaseReloadableService:136] - Initializing shibboleth.AttributeFilterEngine service with resources: [/opt/shibboleth-idp/conf/attribute-filter.xml]
> 2012-04-17 13:29:28,014 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.AttributeFilterEngine
> [...]
> 2012-04-17 13:29:38,791 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:180] - shibboleth.AttributeFilterEngine service loaded new configuration
> Changing to a FileBackedHttpResource, however, makes the startup fail - even if /opt/shibboleth-idp/conf/attribute-filter.xml is still present on the local file system (and has the same contents as before). I.e., changing the snippet in service.xml to
> <srv:Service id="shibboleth.AttributeFilterEngine" xsi:type="attribute-afp:ShibbolethAttributeFilteringEngine"
> configurationResourcePollingFrequency="PT1H" configurationResourcePollingRetryAttempts="128">
> <srv:ConfigurationResource xsi:type="resource:FileBackedHttpResource"
> url="https://www.example.org/my/attribute-filter.xml" file="/opt/shibboleth-idp/conf/attribute-filter.xml"/>
> </srv:Service>
> will only produce this single line in idp-process.log:
> 2012-04-17 13:32:20,142 - DEBUG [edu.internet2.middleware.shibboleth.common.config.BaseReloadableService:136] - Initializing shibboleth.AttributeFilterEngine service with resources: [https://www.example.org/my/attribute-filter.xml]
> after which the IdP cancels the startup. In the container log (and only there) we then see:
> Apr 17, 2012 1:32:20 PM org.apache.catalina.core.StandardContext listenerStart
> SEVERE: Exception sending context initialized event to listener instance of class org.springframework.web.context.ContextLoaderListener
> org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'shibboleth.AttributeFilterEngine': Invocation of init method failed; nested exception is edu.internet2.middleware.
> shibboleth.common.service.ServiceException: Unable to initialize service: shibboleth.AttributeFilterEngine
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1338)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:473)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
> at java.security.AccessController.doPrivileged(Native Method)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
> at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
> at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
> at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
> at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
> at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
> at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:429)
> at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728)
> at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:380)
> at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:255)
> at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:199)
> at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:45)
> at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3972)
> at org.apache.catalina.core.StandardContext.start(StandardContext.java:4467)
> at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
> at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:526)
> at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
> at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java: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(LifecycleSupport.java:119)
> at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
> at org.apache.catalina.core.StandardHost.start(StandardHost.java:722)
> at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
> at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
> at org.apache.catalina.core.StandardService.start(StandardService.java:516)
> at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
> at org.apache.catalina.startup.Catalina.start(Catalina.java:593)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:616)
> at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
> Caused by: edu.internet2.middleware.shibboleth.common.service.ServiceException: Unable to initialize service: shibboleth.AttributeFilterEngine
> at edu.internet2.middleware.shibboleth.common.config.BaseReloadableService.initialize(BaseReloadableService.java:150)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:616)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1414)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1375)
> at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1335)
> ... 39 more
> Caused by: org.opensaml.util.resource.ResourceException: Unable to contact resource URL: https://www.example.org/my/attribute-filter.xml
> at org.opensaml.util.resource.HttpResource.exists(HttpResource.java:94)
> at org.opensaml.util.resource.FileBackedHttpResource.exists(FileBackedHttpResource.java:120)
> at org.opensaml.util.resource.ResourceChangeWatcher.<init>(ResourceChangeWatcher.java:114)
> at edu.internet2.middleware.shibboleth.common.config.BaseReloadableService.initialize(BaseReloadableService.java:141)
> ... 46 more
> Caused by: java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
> at java.net.Socket.connect(Socket.java:546)
> at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:584)
> at sun.security.ssl.SSLSocketImpl.<init>(SSLSocketImpl.java:426)
> at sun.security.ssl.SSLSocketFactoryImpl.createSocket(SSLSocketFactoryImpl.java:142)
> at org.apache.commons.httpclient.protocol.SSLProtocolSocketFactory.createSocket(SSLProtocolSocketFactory.java:82)
> at org.apache.commons.httpclient.protocol.SSLProtocolSocketFactory.createSocket(SSLProtocolSocketFactory.java:127)
> at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707)
> at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387)
> at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
> at org.opensaml.util.resource.HttpResource.exists(HttpResource.java:87)
> ... 49 more
> Apr 17, 2012 1:32:20 PM org.apache.catalina.core.ApplicationContext log
> INFO: Closing Spring root WebApplicationContext
> In my understanding, the BaseReloadableService should try to fall back to the backup copy (and the IdP continue with the startup, therefore). And second, can the logging in case of AttributeFilterEngine startup errors be improved, so that it is also seen in idp-process.log?
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the commits
mailing list