Fresh IdP - idp-process.log shows 15 min gap

Wed Mar 7 16:03:46 EST 2018

Hello!

I am performing a fresh install as root on a centos7 cloud image VM using:
+ jetty-distribution-9.4.8.v20171121
+ shibboleth-identity-provider-3.3.2
+ openjdk version "1.8.0_161"

Quick summary of the installation steps:
+yum install java
+untar binaries
+symbolic link /usr/local/jetty-dist to /usr/local/jetty
+new service that uses $JETTY_BASE:
++ExecStart=/usr/bin/java -Djetty.home=/usr/local/jetty
-Djetty.base=/opt/jettyb -jar /usr/local/jetty/start.jar STOP.PORT=10000
STOP.KEY=STOP
++ExecStop= /usr/bin/java -jar /usr/local/jetty/start.jar STOP.PORT=10000
STOP.KEY=STOP --stop
++User=root
+use shibboleth installations script
+create idp.xml webapp context.

TL;DR core log issue:
2018-03-07 *18:57:42,717* - INFO
[net.shibboleth.ext.spring.util.SchemaTypeAwareXMLBeanDefinitionReader:317]
- Loading XML bean definitions from file
[/opt/shibboleth-idp/conf/attribute-filter.xml]
2018-03-07 *19:13:10,316* - INFO
[net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:581]
- Refreshing ApplicationContext:shibboleth.AttributeFilterService: startup
date [Wed Mar 07 19:13:10 UTC 2018]; parent: Root WebApplicationContext

Early issues:
I could not get the jetty.sh start/stop script work to when I placed the
idp.xml context within the webapps dir, but jetty would start and service
requests without idp.xml. With it, it would always fail after several
moments, and idp-process.log would always end at (Loading XML bean
definitions from file [/opt/shibboleth-idp/conf/attribute-filter.xml]).
Which is why I created the separate service using output from jetty.sh's
env_dump().

Log issue:

systemctl start <myservice> and jetty.sh would always log up to the same
point and either fail or hang, with no additional logs or anything I could
really dig deeper with:

2018-03-07 18:25:01,728 - INFO
[net.shibboleth.idp.log.LogbackLoggingService:240] - Shibboleth IdP Version
3.3.2
2018-03-07 18:25:01,734 - INFO
[net.shibboleth.idp.log.LogbackLoggingService:241] - Java
version='1.8.0_161' vendor='Oracle Corporation'
2018-03-07 18:25:01,740 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:199]
- Service 'shibboleth.LoggingService': Reload time set to: 300000, starting
refresh thread
2018-03-07 18:25:01,793 - INFO
[org.opensaml.core.config.InitializationService:48] - Initializing OpenSAML
using the Java Services API
2018-03-07 18:25:02,675 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmlenc#ripemd160
2018-03-07 18:25:02,683 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmldsig-more#hmac-ripemd160
2018-03-07 18:25:02,700 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmldsig-more#rsa-ripemd160
2018-03-07 18:25:03,103 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:172]
- Service 'shibboleth.AttributeFilterService': Performing initial load
2018-03-07 18:25:03,103 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:258]
- Service 'shibboleth.AttributeFilterService': Reloading service
configuration
2018-03-07 18:25:03,109 - INFO
[net.shibboleth.ext.spring.util.SchemaTypeAwareXMLBeanDefinitionReader:317]
- Loading XML bean definitions from file
[/opt/shibboleth-idp/conf/attribute-filter.xml]
2018-03-07 18:41:16,992 - INFO
[net.shibboleth.idp.log.LogbackLoggingService:240] - Shibboleth IdP Version
3.3.2
2018-03-07 18:41:17,002 - INFO
[net.shibboleth.idp.log.LogbackLoggingService:241] - Java
version='1.8.0_161' vendor='Oracle Corporation'
2018-03-07 18:41:17,008 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:199]
- Service 'shibboleth.LoggingService': Reload time set to: 300000, starting
refresh thread
2018-03-07 18:41:17,071 - INFO
[org.opensaml.core.config.InitializationService:48] - Initializing OpenSAML
using the Java Services API
2018-03-07 18:41:17,907 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmlenc#ripemd160
2018-03-07 18:41:17,913 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmldsig-more#hmac-ripemd160
2018-03-07 18:41:17,925 - INFO
[org.opensaml.xmlsec.algorithm.AlgorithmRegistry:206] - Algorithm failed
runtime support check, will not be usable:
http://www.w3.org/2001/04/xmldsig-more#rsa-ripemd160
2018-03-07 18:41:18,310 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:172]
- Service 'shibboleth.AttributeFilterService': Performing initial load
2018-03-07 18:41:18,311 - INFO
[net.shibboleth.utilities.java.support.service.AbstractReloadableService:258]
- Service 'shibboleth.AttributeFilterService': Reloading service
configuration
2018-03-07 18:41:18,317 - INFO
[net.shibboleth.ext.spring.util.SchemaTypeAwareXMLBeanDefinitionReader:317]
- Loading XML bean definitions from file
[/opt/shibboleth-idp/conf/attribute-filter.xml]

Before lunch I started jetty and then left. Upon returning I found jetty had
booted with idp.xml and was servicing browser requests for <ip>/idp. Looking
at idp-process.log showed a 15 min gap though which is really weird.
/opt/shibboleth-idp/bin//status.sh is also getting a connection refused, and
curl <ip>/idp returns nothing from a separate VM. Any ideas why I am
experiencing some oddness would help a lot.

My start.ini:

java -jar /usr/local/jetty/start.jar
--add-to-start=http,server,deploy,annotations,resources,console-capture,requestlog,servlets,jsp,jstl,ext,plus

appended with:
-Didp.home=/opt/shibboleth-idp
-XX:+UseG1GC
-Xmx1500m
-Djava.io.tmpdir=temp

firewalld:

firewall-cmd --zone=public --add-forward-port=port=80:proto=tcp:toport=8080
--permanent
firewall-cmd --zone=public --add-forward-port=port=443:proto=tcp:toport=8443
--permanent
firewall-cmd --zone=public --add-port=80/tcp --permanent
firewall-cmd --zone=public --add-port=443/tcp --permanent

Thanks!

--
Sent from: http://shibboleth.1660669.n2.nabble.com/Shibboleth-Users-f1660767.html