I'm trying to set up ESOE with a spep both running under the same
context of tomcat 5.5 on a linux machine.
I don't have all the LDAP settings, just the url, and hope to complete
the configuration of this later. I am able to enter and complete
esoestartup wizard, but I'm not able to access the esoemanager, just
get the following error:
javax.servlet.ServletException: An error occurred while this server
was starting up.
com.qut.middleware.spep.filter.SPEPFilter.doFilter(SPEPFilter.java:
119)
I'm not getting any logging in the spep.data directory, so can't
provide any info here.
There is stack in the output from catalina.out, but only info:
INFO: Server startup in 17991 ms
java.lang.IllegalStateException: Metadata was not successfully loaded
at
com.qut.middleware.spep.metadata.impl.MetadataImpl.waitForData(MetadataImpl .java:
380)
at
com.qut.middleware.spep.metadata.impl.MetadataImpl.getSPEPStartupServiceEnd point(MetadataImpl.java:
325)
at
com.qut.middleware.spep.impl.StartupProcessorImpl.doStartup(StartupProcesso rImpl.java:
211)
at com.qut.middleware.spep.impl.StartupProcessorImpl
$StartupProcessorThread.run(StartupProcessorImpl.java:358)
If you load that URL up in your browser, you should see an XML file (or an XML file will be downloaded).
Assuming that is all configured correctly, if you are still seeing this message immediately upon startup try waiting a few minutes. If the /esoemanager context is not initialized before the /spep context, metadata may fail to resolve on the first attempt. This is a self correcting problem, as the metadata processor will retry after the configured interval, which defaults to 2 minutes.
The metadata URL does not seem to be configured correctly if your
expecting an xml file under https. The startup wizard has defined this
automatically in the spep.config as metadataUrl=http://esoe/ esoemanager/metadata/retrieve.htm, despite using https for both the
ESOE identifier and Service URL (registeresoe-stage3.htm) of the ESOE
configuration page.
On Jul 29, 6:29 am, "Shaun Mangelsdorf" <s.mangelsd...@gmail.com>
wrote:
> If you load that URL up in your browser, you should see an XML file (or an
> XML file will be downloaded).
> Assuming that is all configured correctly, if you are still seeing this
> message immediately upon startup try waiting a few minutes. If the
> /esoemanager context is not initialized before the /spep context, metadata
> may fail to resolve on the first attempt. This is a self correcting problem,
> as the metadata processor will retry after the configured interval, which
> defaults to 2 minutes.
The metadata URL does not seem to be configured correctly if your
> expecting an xml file under https.
It doesn't need to be https to work (although, we recommend https for all production deployments), as long as the URL is accessible. Have you tried copying that URL from spep.config to your browser, to see if you can get the metadata document?
Is there any error output in the manager.data, under logging?
Other useful checks would include ensuring that the hostname for the service URL resolves correctly via nslookup on the computer hosting ESOE, checking that tomcat logs the "/esoemanager" and "/" contexts starting, and unpacks esoemanager.war and ROOT.war correctly in your webapps directory, and confirming that it is listening on the port and IP address you would expect (80 for http, 443 for https, or whatever non-standard port is in the URL, if any).
The startup wizard has defined this
> automatically in the spep.config as metadataUrl=http://esoe/ > esoemanager/metadata/retrieve.htm<http://esoe/esoemanager/metadata/retrieve.htm>, > despite using https for both the > ESOE identifier and Service URL (registeresoe-stage3.htm) of the ESOE > configuration page.
If this is the URL it set for metadata, perhaps it is also specified as http:// in other places as well. Again, these don't really need to be https. The easiest way to correct it is by wiping the database and running the esoestartup process again, checking carefully that you have used the right protocol. I've never seen esoestartup mess http/https URLs up like that before, but you can't fix the esoe entity ID and service host if the initial config isn't completed correctly.
The hostname resolves fine on the box hosting ESOE, and I have re-
configured the database, and gone through the esoestartup process
again, this time keeping the protocols the same, ie https and
therefore not specifying a port as default is 443 as you say.
ESOE Configuration:-
ESOE common domain: esoe
ESOE Identifier: https://esoe ESOE Service URL https://esoe
I deploy the remaing war files as instructed which deploy normally
apart from the spep which logs the following errors.
The catalina.log repeats when it hits IllegalStateException: Metadata
was not successfully loaded
The spep.log repeats afterwards from the first fatal to connection
refused
### catalina.log START ###
Jul 30, 2008 9:52:51 AM org.apache.catalina.startup.HostConfig
deployWAR
INFO: Deploying web application archive spep.war
log4j: Threshold ="null".
log4j: Retreiving an instance of org.apache.log4j.Logger.
log4j: Setting [com.qut.middleware.spep] additivity to [true].
log4j: Level value for com.qut.middleware.spep is [INFO].
log4j: com.qut.middleware.spep level set to INFO
log4j: Class name: [org.apache.log4j.DailyRollingFileAppender]
log4j: Setting property [file] to [/home/esoe/opt/esoe/spep/logging/
spep.log].
log4j: Setting property [datePattern] to ['.'yyyy-MM-dd].
log4j: Parsing layout of class: "org.apache.log4j.PatternLayout"
log4j: Setting property [conversionPattern] to [%d %-5p %c - %m%n].
log4j: setFile called: /home/esoe/opt/esoe/spep/logging/spep.log, true
log4j: setFile ended
log4j: Appender [spep-core-logger] to be rolled at midnight.
log4j: Adding appender named [spep-core-logger] to category
[com.qut.middleware.spep].
log4j: Retreiving an instance of org.apache.log4j.Logger.
log4j: Setting [spep.authn] additivity to [true].
log4j: Level value for spep.authn is [INFO].
log4j: spep.authn level set to INFO
log4j: Class name: [org.apache.log4j.DailyRollingFileAppender]
log4j: Setting property [file] to [/home/esoe/opt/esoe/spep/logging/
spep-authn.log].
log4j: Setting property [datePattern] to ['.'yyyy-MM-dd].
log4j: Parsing layout of class: "org.apache.log4j.PatternLayout"
log4j: Setting property [conversionPattern] to [%d %-5p %c - %m%n].
log4j: setFile called: /home/esoe/opt/esoe/spep/logging/spep-
authn.log, true
log4j: setFile ended
log4j: Appender [spep-authn-logger] to be rolled at midnight.
log4j: Adding appender named [spep-authn-logger] to category
[spep.authn].
log4j: Retreiving an instance of org.apache.log4j.Logger.
log4j: Setting [spep.authz] additivity to [true].
log4j: Level value for spep.authz is [INFO].
log4j: spep.authz level set to INFO
log4j: Class name: [org.apache.log4j.DailyRollingFileAppender]
log4j: Setting property [file] to [/home/esoe/opt/esoe/spep/logging/
spep-authz.log].
log4j: Setting property [datePattern] to ['.'yyyy-MM-dd].
log4j: Parsing layout of class: "org.apache.log4j.PatternLayout"
log4j: Setting property [conversionPattern] to [%d %-5p %c - %m%n].
log4j: setFile called: /home/esoe/opt/esoe/spep/logging/spep-
authz.log, true
log4j: setFile ended
log4j: Appender [spep-authz-logger] to be rolled at midnight.
log4j: Adding appender named [spep-authz-logger] to category
[spep.authz].
log4j: Retreiving an instance of org.apache.log4j.Logger.
log4j: Setting [com.qut.middleware.saml2] additivity to [true].
log4j: Level value for com.qut.middleware.saml2 is [INFO].
log4j: com.qut.middleware.saml2 level set to INFO
log4j: Class name: [org.apache.log4j.DailyRollingFileAppender]
log4j: Setting property [file] to [/home/esoe/opt/esoe/spep/logging/
saml2.log].
log4j: Setting property [datePattern] to ['.'yyyy-MM-dd].
log4j: Parsing layout of class: "org.apache.log4j.PatternLayout"
log4j: Setting property [conversionPattern] to [%d %-5p %c - %m%n].
log4j: setFile called: /home/esoe/opt/esoe/spep/logging/saml2.log,
true
log4j: setFile ended
log4j: Appender [saml2-logger] to be rolled at midnight.
log4j: Adding appender named [saml2-logger] to category
[com.qut.middleware.saml2].
log4j:WARN No appenders could be found for logger
(org.apache.commons.digester.Digester.sax).
log4j:WARN Please initialize the log4j system properly.
java.lang.IllegalStateException: Metadata was not successfully loaded
at
com.qut.middleware.spep.metadata.impl.MetadataImpl.waitForData(MetadataImpl .java:
380)
at
com.qut.middleware.spep.metadata.impl.MetadataImpl.getSPEPStartupServiceEnd point(MetadataImpl.java:
325)
at
com.qut.middleware.spep.impl.StartupProcessorImpl.doStartup(StartupProcesso rImpl.java:
211)
at com.qut.middleware.spep.impl.StartupProcessorImpl
$StartupProcessorThread.run(StartupProcessorImpl.java:358)
java.lang.IllegalStateException: Metadata was not successfully loaded
### catalina.log END ###
### esoemanager.log START ###
2008-07-30 09:44:00,325 INFO
com.qut.middleware.esoemanager.DynamicSqlMapClientFactoryBean -
Setting database LOB handler to DEFAULT
2008-07-30 10:05:32,990 INFO
com.qut.middleware.esoemanager.metadata.MetadataUpdateMonitor -
Terminating thread for class ESOEManager Metadata update monitor
### esoemanager.log END ###
### spep.log START ###
2008-07-30 09:52:51,956 INFO com.qut.middleware.spep.Initializer -
Configured spep.data from java property spep.data, with a value of: /
home/esoe/opt/esoe/spep
2008-07-30 09:52:52,421 INFO
com.qut.middleware.spep.metadata.impl.MetadataThread - Created
MetadataThread successfully with params - interval: 120 seconds.
2008-07-30 09:52:52,421 INFO
com.qut.middleware.spep.metadata.impl.MetadataImpl - Created
MetadataImpl successfully with params spepIdentifier=https://
wks004.mp4.informaworld.com/esoemanager, esoeIdentifier=https://
wks004.mp4.informaworld.com, metadataUrl=https://
wks004.mp4.informaworld.com/esoemanager/metadata/retrieve.htm,
interval=120
2008-07-30 09:52:52,478 INFO
com.qut.middleware.spep.ws.impl.WSClientImpl - Created WSClientImpl
successfully
2008-07-30 09:52:52,500 ERROR
com.qut.middleware.spep.metadata.impl.MetadataThread - I/O error
occurred reading metadata. Exception was: Connection refused
2008-07-30 09:52:52,513 INFO
com.qut.middleware.spep.sessions.impl.SessionCacheImpl - Created
SessionCacheImpl successfully
2008-07-30 09:52:52,518 INFO
com.qut.middleware.spep.impl.IdentifierCacheMonitor - IdentifierCache
monitor Thread. sucesfully started with params - interval: 120,000,
timeout: 36,000,000
2008-07-30 09:52:52,917 INFO
com.qut.middleware.spep.attribute.impl.AttributeProcessorImpl -
Created AttributeProcessorImpl successfully.
2008-07-30 09:52:54,382 INFO
com.qut.middleware.spep.pep.impl.PolicyEnforcementProcessorImpl -
Created PolicyEnforcementProcessorImpl successfully
2008-07-30 09:52:54,664 INFO
com.qut.middleware.spep.impl.StartupProcessorImpl - Created
StartupProcessorImpl successfully.
2008-07-30 09:52:54,665 INFO
com.qut.middleware.spep.impl.StartupProcessorImpl - Initiating SPEP
startup.
2008-07-30 09:52:54,791 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:53:14,796 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-07-30 09:53:14,852 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:53:34,858 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-07-30 09:53:34,915 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:53:54,919 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-07-30 09:53:54,974 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:54:14,979 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-07-30 09:54:15,032 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:54:35,037 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-07-30 09:54:35,093 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-07-30 09:54:52,533 INFO
com.qut.middleware.spep.sessions.impl.SessionCacheImpl$CleanupThread -
Cleaning up timed out Principal Sessions ...
2008-07-30 09:54:52,534 ERROR
com.qut.middleware.spep.metadata.impl.MetadataThread - I/O error
occurred reading metadata. Ignoring new metadata. Exception was:
Connection refused
### spep.log END ###
On Jul 29, 10:06 pm, "Shaun Mangelsdorf" <s.mangelsd...@gmail.com>
wrote:
There's your problem, connection refused to the metadata URL. If you can fix that, I bet it will start working fine. By default, Tomcat does not listen on the standard https port. Have you specified a connector for that port in your server.xml?
I've now set up https, and created a certificate using keytool, tested
and works fine for tomcat manager and other web apps. I am however
getting a different error in the spep.log:
SunCertPathBuilderException: unable to find valid certification path
to requested target
Should I be generating my own certificate at all, if not what should
be going into the server.xml.
Thanks
On Jul 30, 11:24 am, "Shaun Mangelsdorf" <s.mangelsd...@gmail.com>
wrote:
> There's your problem, connection refused to the metadata URL. If you can fix
> that, I bet it will start working fine. By default, Tomcat does not listen
> on the standard https port. Have you specified a connector for that port in
> your server.xml?
If you generate your own self-signed certificate, you need to import it into your list of trusted CAs. In Java, you just need to use keytool to import your certificate to $JAVA_HOME/jre/lib/security/cacerts - assuming the default layout of the Java installation. The default password for that keystore is "changeit" (without quotes); if you haven't changed it.
> I've now set up https, and created a certificate using keytool, tested > and works fine for tomcat manager and other web apps. I am however > getting a different error in the spep.log:
> SunCertPathBuilderException: unable to find valid certification path > to requested target
> Should I be generating my own certificate at all, if not what should > be going into the server.xml.
> > There's your problem, connection refused to the metadata URL. If you can > fix > > that, I bet it will start working fine. By default, Tomcat does not > listen > > on the standard https port. Have you specified a connector for that port > in > > your server.xml?
I've added the generated cert to the cacerts keystore, and this is
also referenced in the server.xml, but I'm still getting errors with
the spep. I'm also running https on a different port - 9443 as oppose
to 443 as this is reserved for another application.
==> /home/esoe/opt/esoe/spep/logging/spep.log <==
2008-08-05 17:02:34,260 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-08-05 17:02:34,306 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-08-05 17:02:45,089 INFO
com.qut.middleware.spep.sessions.impl.SessionCacheImpl$CleanupThread -
Cleaning up timed out Principal Sessions ...
==> /home/esoe/opt/esoe/spep/logging/saml2.log <==
2008-08-05 17:02:54,312 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
==> /home/esoe/opt/esoe/spep/logging/spep.log <==
2008-08-05 17:02:54,310 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-08-05 17:02:54,357 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-08-05 17:02:58,157 ERROR
com.qut.middleware.spep.metadata.impl.MetadataThread - I/O error
occurred reading metadata. Ignoring new metadata. Exception was:
sun.security.validator.ValidatorException: PKIX path building failed:
sun.security.provider.certpath.SunCertPathBuilderException: unable to
find valid certification path to requested target
==> /home/esoe/opt/esoe/manager/logging/esoemanager.log <==
2008-08-05 14:54:52,371 INFO
com.qut.middleware.esoemanager.metadata.MetadataUpdateMonitor -
Terminating thread for class ESOEManager Metadata update monitor
2008-08-05 15:12:39,124 INFO
com.qut.middleware.esoemanager.DynamicSqlMapClientFactoryBean -
Setting database LOB handler to DEFAULT
==> /home/esoe/opt/esoe/manager/logging/saml2.log <==
2008-08-05 15:12:39,471 INFO
com.qut.middleware.saml2.identifier.impl.IdentifierCacheImpl - Created
IdentifierCacheImpl successfully
2008-08-05 15:12:40,101 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:40,269 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:40,431 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:41,179 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:41,409 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Created signing
MarshallerImpl successfully
2008-08-05 15:12:41,660 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Created non
signing MarshallerImpl successfully
2008-08-05 15:12:41,794 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Created non
signing MarshallerImpl successfully
2008-08-05 15:12:41,923 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:41,951 INFO
com.qut.middleware.saml2.handler.impl.UnmarshallerImpl - Created
UnmarshallerImpl successfully
2008-08-05 15:12:42,131 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
==> /home/esoe/opt/esoe/manager/logging/spepfilter.log <==
2008-08-05 15:17:22,304 FATAL
com.qut.middleware.spep.filter.SPEPFilter - Unable to process request
to acces resource, SPEP is not initialized correcty
2008-08-05 15:22:25,775 FATAL
com.qut.middleware.spep.filter.SPEPFilter - Unable to process request
to acces resource, SPEP is not initialized correcty
==> /home/esoe/opt/esoe/manager/logging/saml2.log <==
2008-08-05 15:22:42,548 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
==> /home/esoe/opt/esoe/manager/logging/spepfilter.log <==
2008-08-05 15:23:32,777 FATAL
com.qut.middleware.spep.filter.SPEPFilter - Unable to process request
to acces resource, SPEP is not initialized correcty
==> /home/esoe/opt/esoe/manager/logging/saml2.log <==
2008-08-05 15:32:42,732 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
2008-08-05 15:42:42,914 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
Thanks
On Jul 31, 9:33 pm, "Shaun Mangelsdorf" <s.mangelsd...@gmail.com>
wrote:
> If you generate your own self-signed certificate, you need to import it into
> your list of trusted CAs. In Java, you just need to use keytool to import
> your certificate to $JAVA_HOME/jre/lib/security/cacerts - assuming the
> default layout of the Java installation. The default password for that
> keystore is "changeit" (without quotes); if you haven't changed it.
> > I've now set up https, and created a certificate using keytool, tested
> > and works fine for tomcat manager and other web apps. I am however
> > getting a different error in the spep.log:
> > SunCertPathBuilderException: unable to find valid certification path
> > to requested target
> > Should I be generating my own certificate at all, if not what should
> > be going into the server.xml.
> > > There's your problem, connection refused to the metadata URL. If you can
> > fix
> > > that, I bet it will start working fine. By default, Tomcat does not
> > listen
> > > on the standard https port. Have you specified a connector for that port
> > in
> > > your server.xml?
I've added the generated cert to the cacerts keystore, and this is
also referenced in the server.xml, but I'm still getting errors with
the spep. I'm also running https on a different port (9443 as oppose
to 443) as this is reserved for another application.
==> /home/esoe/opt/esoe/spep/logging/spep.log <==
2008-08-05 17:02:34,260 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-08-05 17:02:34,306 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-08-05 17:02:45,089 INFO
com.qut.middleware.spep.sessions.impl.SessionCacheImpl$CleanupThread -
Cleaning up timed out Principal Sessions ...
==> /home/esoe/opt/esoe/spep/logging/saml2.log <==
2008-08-05 17:02:54,312 INFO
com.qut.middleware.saml2.handler.impl.MarshallerImpl - Marshaller is
using RSA key for cryptography
==> /home/esoe/opt/esoe/spep/logging/spep.log <==
2008-08-05 17:02:54,310 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - SPEP did not
recieve authorization from the ESOE to continue. Waiting 20 seconds
before attempting startup again.
2008-08-05 17:02:54,357 FATAL
com.qut.middleware.spep.impl.StartupProcessorImpl - Unexpected error
prevented SPEP startup. Message was: Metadata was not successfully
loaded
2008-08-05 17:02:58,157 ERROR
com.qut.middleware.spep.metadata.impl.M