OIDC plugin installation fails behind HTTP proxy
Manuel Haim
haim at hrz.uni-marburg.de
Wed Jun 2 14:07:01 UTC 2021
Hi list,
I am trying to install the OIDC plugin on an internal server which
requires a HTTP proxy for internet connection
(IdP 4.1.2 / Debian GNU/Linux 10 / OpenJDK 11).
So is there a default way to specify HTTP proxy settings for the
plugin installer? I could not find one in the wiki, and my attempts to
define another HTTP client bean with the proxy settings did not work
out as expected (see below).
My first try without explicitly defining the HTTP proxy failed:
# /opt/shibboleth-idp/bin/plugin.sh -i oidc-common-dist-1.1.0.tar.gz
INFO - Plugin net.shibboleth.oidc.common: Trust store folder does not
exist, creating
INFO - Plugin net.shibboleth.oidc.common: Trust store does not exist,
creating
INFO - TrustStore does not contain signature 0X7D27E610B8A3DC52
Accept this key:
Signature: 0X7D27E610B8A3DC52
FingerPrint: B5B5DD332142AD657E8D87AC7D27E610B8A3DC52
Username: Philip David Smart <philip.smart at jisc.ac.uk>
[yN] y
INFO - Plugin net.shibboleth.oidc.common: HTTPResource
[https://shibboleth.net/downloads/identity-provider/plugins/plugins.properties] could not be
located
INFO - Plugin net.shibboleth.oidc.common: HTTPResource
[http://plugins.shibboleth.net/plugins.properties] could not be located
ERROR - Plugin net.shibboleth.oidc.common: No available servers found.
ERROR - Plugin Install failed:
org.apache.tools.ant.BuildException:
net.shibboleth.utilities.java.support.component.ComponentInitializationException: Could not locate information for
net.shibboleth.oidc.common
at
net.shibboleth.idp.installer.plugin.impl.PluginInstaller.installPlugin(PluginInstaller.java:252)
Caused by:
net.shibboleth.utilities.java.support.component.ComponentInitializationException: Could not locate information for
net.shibboleth.oidc.common
at
net.shibboleth.idp.installer.plugin.impl.PluginState.doInitialize(PluginState.java:317)
So in order to use our HTTP proxy, I modified the file
net/shibboleth/idp/conf/http-client.xml within idp-conf-impl-4.1.2.jar
and created a copy of the shibboleth.InternalHttpClient bean
definition with additional connectionProxyHost and connectionProxyPort
settings:
<bean id="shibboleth.UMRProxyHttpClient"
parent="shibboleth.HttpClientFactory" lazy-init="true"
p:tLSSocketFactory="#{
%{idp.httpclient.useTrustEngineTLSSocketFactory:false} or
%{idp.httpclient.useSecurityEnhancedTLSSocketFactory:false} ?
@'shibboleth.SecurityEnhancedTLSSocketFactory' : null }"
p:connectionDisregardTLSCertificate="%{idp.httpclient.connectionDisregardTLSCertificate:false}"
p:connectionTimeout="%{idp.httpclient.connectionTimeout:PT1M}"
p:connectionRequestTimeout="%{idp.httpclient.connectionRequestTimeout:PT1M}"
p:socketTimeout="%{idp.httpclient.socketTimeout:PT1M}"
p:maxConnectionsTotal="%{idp.httpclient.maxConnectionsTotal:100}"
p:maxConnectionsPerRoute="%{idp.httpclient.maxConnectionsPerRoute:100}"
p:connectionProxyHost="%{idp.http.proxyhost:www-proxy1.uni-marburg.de}"
p:connectionProxyPort="%{idp.http.proxyport:3128}" />
Then I tried to run the installation (this time with the new HTTP
client and verbose output):
# /opt/shibboleth-idp/bin/plugin.sh --verbose -hc
shibboleth.UMRProxyHttpClient -i oidc-common-dist-1.1.0.tar.gz
The output shows that the shibboleth.UMRProxyHttpClient is
instantiated, but I still get a "Connection discarded" message:
2021-06-02 15:35:22,445 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI:265] -
Initializing Spring context with [class path resource
[net/shibboleth/idp/conf/http-client.xml]]
2021-06-02 15:35:22,625 - DEBUG
[net.shibboleth.ext.spring.util.SchemaTypeAwareXMLBeanDefinitionReader:393] -
Loaded 13 bean definitions from class path resource
[net/shibboleth/idp/conf/http-client.xml]
2021-06-02 15:35:22,625 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:95] -
Initializing application context 'ApplicationContext:anonymous,
started on Thu Jan 01 01:00:00 CET 1970'
2021-06-02 15:35:22,632 - DEBUG
[org.springframework.core.env.PropertySourcesPropertyResolver:115] -
Found key 'idp.home' in PropertySource 'systemProperties' with value
of type String
2021-06-02 15:35:22,632 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:105] -
Attempting to find '/conf/idp.properties' at search location
'/opt/shibboleth-idp/bin/..'
2021-06-02 15:35:22,639 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:109] -
Attempting to find resource
'/opt/shibboleth-idp/bin/../conf/idp.properties'
2021-06-02 15:35:22,640 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:113] -
Found resource 'file [/opt/shibboleth-idp/bin/../conf/idp.properties]'
at search path '/opt/shibboleth-idp/bin/../conf/idp.properties'
2021-06-02 15:35:22,641 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:339] -
Setting 'idp.home' property to '/opt/shibboleth-idp/bin/..'
2021-06-02 15:35:22,644 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/admin/admin.properties
2021-06-02 15:35:22,644 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/authn/authn.properties
2021-06-02 15:35:22,645 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/c14n/subject-c14n.properties
2021-06-02 15:35:22,645 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/services.properties
2021-06-02 15:35:22,646 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/ldap.properties
2021-06-02 15:35:22,646 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/saml-nameid.properties
2021-06-02 15:35:22,646 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:233] -
Including auto-located properties in
/opt/shibboleth-idp/bin/../conf/idp.properties
2021-06-02 15:35:22,647 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/admin/admin.properties'
2021-06-02 15:35:22,647 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/admin/admin.properties]'
2021-06-02 15:35:22,647 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/authn/authn.properties'
2021-06-02 15:35:22,647 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/authn/authn.properties]'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/c14n/subject-c14n.properties'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/c14n/subject-c14n.properties]'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/services.properties'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/services.properties]'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/ldap.properties'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/ldap.properties]'
2021-06-02 15:35:22,648 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/saml-nameid.properties'
2021-06-02 15:35:22,649 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/saml-nameid.properties]'
2021-06-02 15:35:22,649 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../conf/idp.properties'
2021-06-02 15:35:22,649 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../conf/idp.properties]'
2021-06-02 15:35:22,649 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:276] -
Attempting to load properties from resource
'/opt/shibboleth-idp/bin/../credentials/secrets.properties'
2021-06-02 15:35:22,649 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:279] -
Found property resource 'file
[/opt/shibboleth-idp/bin/../credentials/secrets.properties]'
2021-06-02 15:35:22,650 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.additionalProperties'='/credentials/secrets.properties'
2021-06-02 15:35:22,650 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.artifact.StorageService'='shibboleth.JPAStorageService'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.baseDN'='%{idp.authn.LDAP.baseDN:undefined}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.bindDN'='%{idp.authn.LDAP.bindDN:undefined}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.bindDNCredential'='<suppressed>'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.connectTimeout'='%{idp.authn.LDAP.connectTimeout:PT3S}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.connectionStrategy'='%{idp.authn.LDAP.connectionStrategy:ACTIVE_PASSIVE}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.ldapURL'='%{idp.authn.LDAP.ldapURL}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.responseTimeout'='%{idp.authn.LDAP.responseTimeout:PT3S}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.searchFilter'='(uid=$resolutionContext.principal)'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.trustCertificates'='%{idp.authn.LDAP.trustCertificates:undefined}'
2021-06-02 15:35:22,651 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.attribute.resolver.LDAP.useStartTLS'='%{idp.authn.LDAP.useStartTLS:true}'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.audit.shortenBindings'='true'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.Duo.supportedPrincipals'='saml2/http://example.org/ac/classes/mfa,
saml1/http://example.org/ac/classes/mfa'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.External.externalAuthnPath'='contextRelative:external.jsp'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.IPAddress.supportedPrincipals'='saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:InternetProtocol'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.authenticator'='bindSearchAuthenticator'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.baseDN'='ou=Accounts,o=Universitaet
Marburg,c=DE'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.LDAP.bindDN'='uid=shibboleth,ou=Proxy,o=Universitaet
Marburg,c=DE'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.bindDNCredential'='<suppressed>'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.LDAP.ldapURL'='ldaps://ldap01.hrz.uni-marburg.de:636
ldaps://ldap02.hrz.uni-marburg.de:636
ldaps://ldap03.hrz.uni-marburg.de:636
ldaps://ldap04.hrz.uni-marburg.de:636'
2021-06-02 15:35:22,652 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.returnAttributes'='uid,objectClass'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.sslConfig'='certificateTrust'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.subtreeSearch'='true'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.LDAP.trustCertificates'='/etc/ssl/certs/T-TeleSec_GlobalRoot_Class_2.pem'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.useSSL'='true'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.useStartTLS'='false'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.authn.LDAP.userFilter'='(uid={user})'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.MFA.supportedPrincipals'='saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:InternetProtocol, saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport, saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:Password,
saml1/urn:oasis:names:tc:SAML:1.0:am:password'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.SPNEGO.supportedPrincipals'='saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:Kerberos,
saml1/urn:ietf:rfc:1510'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.X509.supportedPrincipals'='saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:X509, saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:TLSClient,
saml1/urn:ietf:rfc:2246'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.authn.X509Internal.supportedPrincipals'='saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:X509, saml2/urn:oasis:names:tc:SAML:2.0:ac:classes:TLSClient,
saml1/urn:ietf:rfc:2246'
2021-06-02 15:35:22,653 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.bindings.inMetadataOrder'='false'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.c14n.attribute.attributeSourceIds'='uid'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.c14n.attribute.attributesToResolve'='uid'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.cas.StorageService'='shibboleth.JPAStorageService'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.consent.StorageService'='shibboleth.JPAStorageService'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.consent.allowDoNotRemember'='false'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.consent.allowGlobal'='false'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.consent.attribute-release.userStorageKey'='<suppressed>'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.consent.attribute-release.userStorageKeyAttribute'='<suppressed>'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.consent.compareValues'='true'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.consent.terms-of-use.userStorageKey'='<suppressed>'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.consent.terms-of-use.userStorageKeyAttribute'='<suppressed>'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.csrf.enabled'='true'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.encryption.cert'='%{idp.home}/credentials/idp.crt'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.encryption.config'='shibboleth.EncryptionConfiguration.GCM'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.encryption.key'='<suppressed>'
2021-06-02 15:35:22,654 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.entityID'='https://idp.hrz.uni-marburg.de/idp/shibboleth'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.home'='/opt/shibboleth-idp/bin/..'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.http.proxyhost'='www-proxy1.uni-marburg.de'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.http.proxyport'='3128'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.httpclient.filecaching.cacheDirectory'='%{idp.home}/tmp/httpClientCache'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.logout.elaboration'='true'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.persistentId.computed'=''
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.persistentId.dataSource'='shibboleth.PostgreSQLDataSource'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.persistentId.generator'='shibboleth.StoredPersistentIdGenerator'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.persistentId.sourceAttribute'='uid'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.scope'='uni-marburg.de'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.sealer.keyPassword'='<suppressed>'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.sealer.storePassword'='<suppressed>'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.sealer.storeResource'='%{idp.home}/credentials/sealer.jks'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.sealer.versionResource'='%{idp.home}/credentials/sealer.kver'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.searchForProperties'='true'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.access.checkInterval'='PT5M'
2021-06-02 15:35:22,655 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.attribute.filter.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.attribute.registry.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.attribute.registry.encodeType'='false'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.attribute.resolver.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.cas.registry.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.logging.checkInterval'='PT5M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.managedBean.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.nameidGeneration.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.service.relyingparty.checkInterval'='PT15M'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.service.relyingparty.ignoreUnmappedEntityAttributes'='true'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.session.StorageService'='shibboleth.JPAStorageService'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.session.secondaryServiceIndex'='true'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.session.trackSPSessions'='true'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.signing.cert'='%{idp.home}/credentials/idp.crt'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.signing.key'='<suppressed>'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.status.accessPolicy'='StatusAccessByIPAddress'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.storage.htmlLocalStorage'='true'
2021-06-02 15:35:22,656 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.trust.certificates'='shibboleth.ExplicitKeyX509TrustEngine'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'idp.trust.signatures'='shibboleth.ExplicitKeySignatureTrustEngine'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'idp.ui.fallbackLanguages'='en,fr,de'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'psql.class'='org.apache.tomcat.jdbc.pool.DataSource'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'psql.password'='<suppressed>'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property
'psql.url'='jdbc:postgresql://idp-db04.hrz.uni-marburg.de:5432/shibboleth'
2021-06-02 15:35:22,657 - DEBUG
[net.shibboleth.idp.spring.IdPPropertiesApplicationContextInitializer:306] -
Loaded property 'psql.username'='shibboleth'
2021-06-02 15:35:22,658 - DEBUG
[net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:629] -
Refreshing ApplicationContext:anonymous
2021-06-02 15:35:22,678 - DEBUG
[org.springframework.beans.factory.support.DefaultListableBeanFactory:225] -
Creating shared instance of singleton bean
'shibboleth.PropertySourcesPlaceholderConfigurer'
2021-06-02 15:35:22,719 - DEBUG
[org.springframework.core.env.PropertySourcesPropertyResolver:115] -
Found key 'idp.home' in PropertySource 'systemProperties' with value
of type String
2021-06-02 15:35:22,719 - DEBUG
[org.springframework.core.env.PropertySourcesPropertyResolver:115] -
Found key 'idp.httpclient.filecaching.cacheDirectory' in
PropertySource 'file [/opt/shibboleth-idp/bin/../conf/idp.properties]'
with value of type String
2021-06-02 15:35:22,719 - DEBUG
[org.springframework.core.env.PropertySourcesPropertyResolver:115] -
Found key 'idp.httpclient.filecaching.cacheDirectory' in
PropertySource 'environmentProperties' with value of type String
2021-06-02 15:35:22,732 - DEBUG
[org.springframework.beans.factory.support.DefaultListableBeanFactory:225] -
Creating shared instance of singleton bean
'shibboleth.UMRProxyHttpClient'
2021-06-02 15:35:23,066 - DEBUG
[org.springframework.core.env.PropertySourcesPropertyResolver:115] -
Found key 'idp.home' in PropertySource 'systemProperties' with value
of type String
2021-06-02 15:35:23,077 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:195] - Not windows. Not
[re]setting readonly bit
2021-06-02 15:35:23,077 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:218] - Directory
/opt/shibboleth-idp/dist/plugin-workspace does not exist, not
performing chmod
2021-06-02 15:35:23,077 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:218] - Directory
/opt/shibboleth-idp/dist/plugin-webapp does not exist, not performing
chmod
2021-06-02 15:35:23,077 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:218] - Directory
/opt/shibboleth-idp/dist/plugin-contents does not exist, not
performing chmod
2021-06-02 15:35:23,119 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.TrustStore:349] - Plugin
net.shibboleth.oidc.common: Trust store exists, loading
2021-06-02 15:35:23,140 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.TrustStore:265] - Looking
for key with Id 0X7D27E610B8A3DC52
2021-06-02 15:35:23,192 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.TrustStore:295] - Signature
Check Succeeded
2021-06-02 15:35:23,203 - DEBUG
[net.shibboleth.idp.module.PropertyDrivenIdPModule:143] - Ignoring
plugin 'net.shibboleth.oidc.common' version property in favor of
package manifest
2021-06-02 15:35:23,204 - DEBUG
[net.shibboleth.idp.module.PropertyDrivenIdPModule:175] - Plugin
net.shibboleth.oidc.common loaded
2021-06-02 15:35:23,207 - DEBUG
[net.shibboleth.idp.module.PropertyDrivenIdPModule:212] - Module
idp.oidc.common.1 loaded
2021-06-02 15:35:23,208 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.PluginInstaller:349] - Found
Service announcing itself as net.shibboleth.oidc.common
2021-06-02 15:35:23,212 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.PluginState:298] - Plugin
net.shibboleth.oidc.common: Looking for update at HTTPResource
[https://shibboleth.net/downloads/identity-provider/plugins/plugins.properties]
2021-06-02 15:35:23,212 - DEBUG
[net.shibboleth.ext.spring.resource.HTTPResource:207] - Attempting to
fetch remote resource as
'https://shibboleth.net/downloads/identity-provider/plugins/plugins.properties'
2021-06-02 15:35:23,221 - DEBUG
[org.apache.http.client.protocol.RequestAddCookies:123] - CookieSpec
selected: default
2021-06-02 15:35:23,225 - DEBUG
[org.apache.http.client.protocol.RequestAuthCache:77] - Auth cache not
set in the context
2021-06-02 15:35:23,226 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:267] -
Connection request: [route: {s}->https://shibboleth.net:443][total
available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
2021-06-02 15:35:23,247 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:312] -
Connection leased: [id: 0][route:
{s}->https://shibboleth.net:443][total available: 0; route allocated:
1 of 2; total allocated: 1 of 20]
2021-06-02 15:35:23,248 - DEBUG
[org.apache.http.impl.execchain.MainClientExec:234] - Opening
connection {s}->https://shibboleth.net:443
2021-06-02 15:35:23,254 - DEBUG
[org.apache.http.impl.conn.DefaultHttpClientConnectionOperator:139] -
Connecting to shibboleth.net/3.213.250.186:443
2021-06-02 15:35:54,830 - DEBUG
[org.apache.http.impl.conn.DefaultHttpClientConnectionOperator:166] -
Connect to shibboleth.net/3.213.250.186:443 timed out. Connection will
be retried using another IP address
2021-06-02 15:35:54,831 - DEBUG
[org.apache.http.impl.conn.DefaultHttpClientConnectionOperator:139] -
Connecting to shibboleth.net/2600:1f18:3fe:4202:a0a8:a500:a10a:3350:443
2021-06-02 15:35:54,831 - DEBUG
[org.apache.http.impl.conn.DefaultManagedHttpClientConnection:96] -
http-outgoing-0: Shutdown connection
2021-06-02 15:35:54,831 - DEBUG
[org.apache.http.impl.execchain.MainClientExec:129] - Connection
discarded
2021-06-02 15:35:54,832 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:351] -
Connection released: [id: 0][route:
{s}->https://shibboleth.net:443][total available: 0; route allocated:
0 of 2; total allocated: 0 of 20]
2021-06-02 15:35:54,836 - INFO
[net.shibboleth.idp.installer.plugin.impl.PluginState:301] - Plugin
net.shibboleth.oidc.common: HTTPResource
[https://shibboleth.net/downloads/identity-provider/plugins/plugins.properties] could not be
located
2021-06-02 15:35:54,836 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.PluginState:298] - Plugin
net.shibboleth.oidc.common: Looking for update at HTTPResource
[http://plugins.shibboleth.net/plugins.properties]
2021-06-02 15:35:54,836 - DEBUG
[net.shibboleth.ext.spring.resource.HTTPResource:207] - Attempting to
fetch remote resource as
'http://plugins.shibboleth.net/plugins.properties'
2021-06-02 15:35:54,836 - DEBUG
[org.apache.http.client.protocol.RequestAddCookies:123] - CookieSpec
selected: default
2021-06-02 15:35:54,836 - DEBUG
[org.apache.http.client.protocol.RequestAuthCache:77] - Auth cache not
set in the context
2021-06-02 15:35:54,837 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:267] -
Connection request: [route:
{}->http://plugins.shibboleth.net:80][total available: 0; route
allocated: 0 of 2; total allocated: 0 of 20]
2021-06-02 15:35:54,837 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:312] -
Connection leased: [id: 1][route:
{}->http://plugins.shibboleth.net:80][total available: 0; route
allocated: 1 of 2; total allocated: 1 of 20]
2021-06-02 15:35:54,837 - DEBUG
[org.apache.http.impl.execchain.MainClientExec:234] - Opening
connection {}->http://plugins.shibboleth.net:80
2021-06-02 15:35:54,870 - DEBUG
[org.apache.http.impl.conn.DefaultHttpClientConnectionOperator:139] -
Connecting to plugins.shibboleth.net/52.216.170.226:80
2021-06-02 15:36:26,318 - DEBUG
[org.apache.http.impl.conn.DefaultManagedHttpClientConnection:96] -
http-outgoing-1: Shutdown connection
2021-06-02 15:36:26,318 - DEBUG
[org.apache.http.impl.execchain.MainClientExec:129] - Connection
discarded
2021-06-02 15:36:26,318 - DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager:351] -
Connection released: [id: 1][route:
{}->http://plugins.shibboleth.net:80][total available: 0; route
allocated: 0 of 2; total allocated: 0 of 20]
2021-06-02 15:36:26,319 - INFO
[net.shibboleth.idp.installer.plugin.impl.PluginState:301] - Plugin
net.shibboleth.oidc.common: HTTPResource
[http://plugins.shibboleth.net/plugins.properties] could not be located
2021-06-02 15:36:26,319 - ERROR
[net.shibboleth.idp.installer.plugin.impl.PluginState:316] - Plugin
net.shibboleth.oidc.common: No available servers found.
2021-06-02 15:36:26,320 - DEBUG
[net.shibboleth.idp.installer.plugin.impl.PluginInstallerSupport:70] -
Deleting directory /tmp/plugin-installer-unpack15204284106818937783
2021-06-02 15:36:26,320 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:195] - Not windows. Not
[re]setting readonly bit
2021-06-02 15:36:26,322 - DEBUG
[net.shibboleth.idp.installer.InstallerSupport:195] - Not windows. Not
[re]setting readonly bit
2021-06-02 15:36:26,323 - ERROR
[net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI:181] -
Plugin Install failed:
org.apache.tools.ant.BuildException:
net.shibboleth.utilities.java.support.component.ComponentInitializationException: Could not locate information for
net.shibboleth.oidc.common
at
net.shibboleth.idp.installer.plugin.impl.PluginInstaller.installPlugin(PluginInstaller.java:252)
at
net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI.doRun(PluginInstallerCLI.java:144)
at
net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI.doRun(PluginInstallerCLI.java:61)
at
net.shibboleth.ext.spring.cli.AbstractCommandLine.run(AbstractCommandLine.java:202)
at
net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI.runMain(PluginInstallerCLI.java:452)
at
net.shibboleth.idp.installer.plugin.impl.PluginInstallerCLI.main(PluginInstallerCLI.java:460)
Caused by:
net.shibboleth.utilities.java.support.component.ComponentInitializationException: Could not locate information for
net.shibboleth.oidc.common
at
net.shibboleth.idp.installer.plugin.impl.PluginState.doInitialize(PluginState.java:317)
at
net.shibboleth.utilities.java.support.component.AbstractInitializableComponent.initialize(AbstractInitializableComponent.java:65)
at
net.shibboleth.idp.installer.plugin.impl.PluginInstaller.installPlugin(PluginInstaller.java:250)
... 5 common frames omitted
2021-06-02 15:36:26,325 - DEBUG
[net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:1049] -
Closing ApplicationContext:anonymous, started on Wed Jun 02 15:35:22
CEST 2021
When leaving out the -hc parameter, the output is nearly the same, but
there is one additional line showing that the
shibboleth.InternalHttpClient is instantiated as well:
[...]
2021-06-02 14:52:02,529 - DEBUG
[org.springframework.beans.factory.support.DefaultListableBeanFactory:225] -
Creating shared instance of singleton bean
'shibboleth.UMRProxyHttpClient'
2021-06-02 14:52:02,564 - DEBUG
[org.springframework.beans.factory.support.DefaultListableBeanFactory:225] -
Creating shared instance of singleton bean
'shibboleth.InternalHttpClient'
[...]
Am I missing something out?
Kind regards,
Manuel
More information about the users
mailing list