Issue switching InCommon from FileBacked Metadata Provider to MDQ
Wessel, Keith
kwessel at illinois.edu
Mon Dec 14 21:52:30 UTC 2020
This of course raises questions since the advertised URL [1] uses HTTPS. I'll let InCommon operations address the benefits of using HTTPS and what the proper route from their perspective is.
If you do need to use HTTPS, you'll need to make sure that the root of the cert chain for mdq.incommon.org is in the CA store used by the IdP's HTTP client.
Keith
1.https://spaces.at.internet2.edu/display/MDQ/production-metadata
-----Original Message-----
From: users <users-bounces at shibboleth.net> On Behalf Of Wessel, Keith
Sent: Monday, December 14, 2020 3:49 PM
To: Shib Users <users at shibboleth.net>
Subject: RE: Issue switching InCommon from FileBacked Metadata Provider to MDQ
FWIW, we're using http, not https, to talk to mdq.incommon.org. Since the metadata responses are signed and you're doing signature validation, there's little to be gained IMHO from https. And that would address your SSL handshake error.
Keith
From: users <users-bounces at shibboleth.net> On Behalf Of Hucker, Taylor
Sent: Monday, December 14, 2020 3:43 PM
To: users at shibboleth.net
Subject: Issue switching InCommon from FileBacked Metadata Provider to MDQ
I am testing a new (upgraded from 3.4.7) Shibboleth IdP v4.0.1 environment but getting an handshake error switching to the MDQ metadata provider for InCommon.
Any suggestions on how to resolve or additional things to troubleshoot? I can send full output of logs, was to lengthy to post it all.
My environment is Shibboleth v4.01 >> Tomcat 9 >> Apache (for fronting SSL).
This environment does not face the outside, I am doing host file edits and using my production entityID/URL for testing by pointing it to my test shib instance.
This method has worked for all other SPs and the file backed metdata for InCommon.
The cert on the test box has an alias to the production idp and so does apache.
Old config: (works)
<MetadataProvider id="InCommon" xsi:type="FileBackedHTTPMetadataProvider" metadataURL="http://md.incommon.org/InCommon/InCommon-metadata.xml" backingFile="%{idp.home}/conf/metadata/InCommon-Metadata.xml" requireValidMetadata="true" minRefreshDelay="PT5M0.000S" maxRefreshDelay="PT4H0M0.000S" connectionTimeout="PT5.000S"/>
New config: (does not work)
<MetadataProvider id="incommon" xsi:type="DynamicHTTPMetadataProvider"
maxCacheDuration="PT24H" minCacheDuration="PT10M">
<MetadataFilter xsi:type="SignatureValidation" requireSignedRoot="true"
certificateFile="%{idp.home}/credentials/inc-md-cert-mdq.pem" />
<MetadataFilter xsi:type="RequiredValidUntil" maxValidityInterval="P14D" />
<MetadataQueryProtocol>https://mdq.incommon.org/</MetadataQueryProtocol>
</MetadataProvider>
idp-process.log
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:748] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Found entityID in criteria: https://sso.educause.edu/sp
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:669] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Resolved criteria to entityID: https://sso.educause.edu/sp
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver:455] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Metadata backing store does not contain any EntityDescriptors with the ID: https://sso.educause.edu/sp
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:684] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Did not find requested metadata in backing store, attempting to resolve dynamically
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:801] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Resolving from origin source based on entityID: https://sso.educause.edu/sp
2020-12-14 14:29:25,383 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver:455] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Metadata backing store does not contain any EntityDescriptors with the ID: https://sso.educause.edu/sp
2020-12-14 14:29:25,384 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:837] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Resolving metadata dynamically for entity ID: https://sso.educause.edu/sp
2020-12-14 14:29:25,384 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.MetadataQueryProtocolRequestURLBuilder:138] - Criteria contained entity ID, building on that basis
2020-12-14 14:29:25,385 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.MetadataQueryProtocolRequestURLBuilder:167] - From entityID 'https://sso.educause.edu/sp' and base URL 'https://mdq.incommon.org/', built request URL: https://mdq.incommon.org/entities/https:%2F%2Fsso.educause.edu%2Fsp
2020-12-14 14:29:25,385 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.FunctionDrivenDynamicHTTPMetadataResolver:103] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: URL generated by request builder was: https://mdq.incommon.org/entities/https:%2F%2Fsso.educause.edu%2Fsp
2020-12-14 14:29:25,385 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicHTTPMetadataResolver:290] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Built request URL of: https://mdq.incommon.org/entities/https:%2F%2Fsso.educause.edu%2Fsp
2020-12-14 14:29:25,386 - 10.254.0.2 - DEBUG [org.apache.http.client.protocol.RequestAddCookies:123] - CookieSpec selected: default
2020-12-14 14:29:25,386 - 10.254.0.2 - DEBUG [org.apache.http.client.protocol.RequestAuthCache:77] - Auth cache not set in the context
2020-12-14 14:29:25,387 - 10.254.0.2 - DEBUG [org.apache.http.impl.client.cache.CachingExec:274] - Cache miss
2020-12-14 14:29:25,387 - 10.254.0.2 - DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager:267] - Connection request: [route: {s}->https://mdq.incommon.org:443][total available: 0; route allocated: 0 of 100; total allocated: 0 of 100]
2020-12-14 14:29:25,387 - 10.254.0.2 - DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager:312] - Connection leased: [id: 9][route: {s}->https://mdq.incommon.org:443][total available: 0; route allocated: 1 of 100; total allocated: 1 of 100]
2020-12-14 14:29:25,388 - 10.254.0.2 - DEBUG [org.apache.http.impl.execchain.MainClientExec:234] - Opening connection {s}->https://mdq.incommon.org:443
2020-12-14 14:29:25,462 - 10.254.0.2 - DEBUG [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator:139] - Connecting to mdq.incommon.org/13.225.53.15:443
2020-12-14 14:29:25,506 - 10.254.0.2 - DEBUG [org.apache.http.impl.conn.DefaultManagedHttpClientConnection:96] - http-outgoing-9: Shutdown connection
2020-12-14 14:29:25,506 - 10.254.0.2 - DEBUG [org.apache.http.impl.execchain.MainClientExec:129] - Connection discarded
2020-12-14 14:29:25,507 - 10.254.0.2 - DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager:351] - Connection released: [id: 9][route: {s}->https://mdq.incommon.org:443][total available: 0; route allocated: 0 of 100; total allocated: 0 of 100]
2020-12-14 14:29:25,514 - 10.254.0.2 - ERROR [org.opensaml.saml.metadata.resolver.impl.AbstractDynamicMetadataResolver:869] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Error fetching metadata from origin source
javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131)
2020-12-14 14:29:25,515 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver:455] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Metadata backing store does not contain any EntityDescriptors with the ID: https://sso.educause.edu/sp
2020-12-14 14:29:25,515 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver:606] - Metadata Resolver FunctionDrivenDynamicHTTPMetadataResolver incommon: Candidates iteration was empty, nothing to filter via predicates
2020-12-14 14:29:25,515 - 10.254.0.2 - DEBUG [org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver:262] - Resolved no EntityDescriptors via underlying MetadataResolver, returning empty collection
2020-12-14 14:29:25,516 - 10.254.0.2 - INFO [org.opensaml.saml.common.binding.impl.SAMLMetadataLookupHandler:167] - Message Handler: No metadata returned for https://sso.educause.edu/sp in role {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor with protocol urn:oasis:names:tc:SAML:2.0:protocol
2020-12-14 14:29:25,518 - 10.254.0.2 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:169] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.impl.SAMLAddAttributeConsumingServiceHandler' on INBOUND message context
2020-12-14 14:29:25,518 - 10.254.0.2 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:190] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2020-12-14 14:29:25,518 - 10.254.0.2 - DEBUG [org.opensaml.saml.common.binding.impl.SAMLAddAttributeConsumingServiceHandler:129] - Message Handler: No metadata context found, nothing to do
2020-12-14 14:29:25,525 - 10.254.0.2 - DEBUG [net.shibboleth.idp.saml.profile.impl.InitializeRelyingPartyContextFromSAMLPeer:131] - Profile Action InitializeRelyingPartyContextFromSAMLPeer: Attaching RelyingPartyContext based on SAML peer https://sso.educause.edu/sp
2020-12-14 14:29:25,525 - 10.254.0.2 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:249] - Resolving relying party configuration
2020-12-14 14:29:25,525 - 10.254.0.2 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:255] - Profile request is unverified, returning configuration shibboleth.UnverifiedRelyingParty
2020-12-14 14:29:25,526 - 10.254.0.2 - DEBUG [net.shibboleth.idp.profile.impl.SelectRelyingPartyConfiguration:136] - Profile Action SelectRelyingPartyConfiguration: Found relying party configuration shibboleth.UnverifiedRelyingParty for request
2020-12-14 14:29:25,527 - 10.254.0.2 - WARN [net.shibboleth.idp.profile.impl.SelectProfileConfiguration:118] - Profile Action SelectProfileConfiguration: Profile http://shibboleth.net/ns/profiles/saml2/sso/browser is not available for RP configuration shibboleth.UnverifiedRelyingParty (RPID https://sso.educause.edu/sp)
2020-12-14 14:29:25,529 - 10.254.0.2 - WARN [org.opensaml.profile.action.impl.LogEvent:101] - A non-proceed event occurred while processing the request: InvalidProfileConfiguration
2020-12-14 14:29:25,530 - 10.254.0.2 - DEBUG [org.opensaml.saml.common.profile.logic.DefaultLocalErrorPredicate:142] - No SAMLBindingContext or binding URI available, error must be handled locally
Httdp ssl_error_log:
[Mon Dec 14 14:29:25.292472 2020] [ssl:info] [pid 2292570:tid 140470009173760] [client 10.254.0.2:58798] AH01964: Connection to child 8 established (server idm-shib1-test.tamucc.edu:443)
[Mon Dec 14 14:29:25.292719 2020] [ssl:debug] [pid 2292570:tid 140470009173760] ssl_engine_kernel.c(2384): [client 10.254.0.2:58798] AH02043: SSL virtual host for servername idp.tamucc.edu found
[Mon Dec 14 14:29:25.292729 2020] [ssl:debug] [pid 2292570:tid 140470009173760] ssl_engine_kernel.c(2384): [client 10.254.0.2:58798] AH02043: SSL virtual host for servername idp.tamucc.edu found
[Mon Dec 14 14:29:25.292732 2020] [core:debug] [pid 2292570:tid 140470009173760] protocol.c(2316): [client 10.254.0.2:58798] AH03155: select protocol from , choices=h2,http/1.1 for server idm-shib1-test.tamucc.edu
[Mon Dec 14 14:29:25.344707 2020] [ssl:debug] [pid 2292570:tid 140470009173760] ssl_engine_kernel.c(2269): [client 10.254.0.2:58798] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Mon Dec 14 14:29:25.344895 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(495): AH00831: socache_shmcb_store (0xd3 -> subcache 19)
[Mon Dec 14 14:29:25.344916 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(732): AH00842: expiring 1 and reclaiming 0 removed socache entries
[Mon Dec 14 14:29:25.344919 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(751): AH00843: we now have 1 socache entries
[Mon Dec 14 14:29:25.344922 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(849): AH00847: insert happened at idx=2, data=(437:469)
[Mon Dec 14 14:29:25.344924 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(854): AH00848: finished insert, subcache: idx_pos/idx_used=1/2, data_pos/data_used=218/438
[Mon Dec 14 14:29:25.344926 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(516): AH00834: leaving socache_shmcb_store successfully
[Mon Dec 14 14:29:25.345019 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(495): AH00831: socache_shmcb_store (0x81 -> subcache 1)
[Mon Dec 14 14:29:25.345035 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(849): AH00847: insert happened at idx=0, data=(0:32)
[Mon Dec 14 14:29:25.345038 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(854): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/218
[Mon Dec 14 14:29:25.345041 2020] [socache_shmcb:debug] [pid 2292570:tid 140470009173760] mod_socache_shmcb.c(516): AH00834: leaving socache_shmcb_store successfully
[Mon Dec 14 14:29:25.345192 2020] [ssl:debug] [pid 2292570:tid 140470009173760] ssl_engine_kernel.c(422): [client 10.254.0.2:58798] AH02034: Initial (No.1) HTTPS request received for child 8 (server idm-shib1-test.tamucc.edu:443), referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345260 2020] [authz_core:debug] [pid 2292570:tid 140470009173760] mod_authz_core.c(846): [client 10.254.0.2:58798] AH01628: authorization result: granted (no directives), referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345354 2020] [proxy:debug] [pid 2292570:tid 140470009173760] mod_proxy.c(1255): [client 10.254.0.2:58798] AH01143: Running scheme http handler (attempt 0), referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345360 2020] [proxy_ajp:debug] [pid 2292570:tid 140470009173760] mod_proxy_ajp.c(743): [client 10.254.0.2:58798] AH00894: declining URL http://localhost:8080/idp/profile/SAML2/Redirect/SSO?SAMLRequest=fZJdT8IwFIb%2FytL7raN8DBogQbmQBANh6IU3pHZn0mRrZ09r8N%2B7DaYYI1fN%2BXifnvO2UxRlUfGFd0e9g3cP6IJTWWjkbWFGvNXcCFTItSgBuZM8XTyuOYtiXlnjjDQFuZLcVghEsE4ZTYLVckYOojfuj%2BN80k8mw9FAJHksxBjEUCb9PMlhlDelTPbjEQmewWKtnJEaVMsRPaw0OqFdnYpZHPZY2BvsWczZhLPhCwmW9TZKC9eqjs5VyClVWRU5UXopI8h8E9J6j1wVQJsxGd1BpixIR9N0Q4JFN%2FG90ehLsCnYDyXhabf%2BYSKaBiaFR2ippcl8AVF1rGhjCsXzyUIhsc123Yf67tMnCbYXK%2B%2BUzpR%2Bu%2B3i67kJ%2BcN%2Bvw23m3RP5tOGz1tX7PzfubCa0uvG6fn5U2mqGtiFl48AdrWco3IgjQXeSX%2BXu9w3gf79UPMv, referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345364 2020] [proxy_fcgi:debug] [pid 2292570:tid 140470009173760] mod_proxy_fcgi.c(1021): [client 10.254.0.2:58798] AH01076: url: http://localhost:8080/idp/profile/SAML2/Redirect/SSO?SAMLRequest=fZJdT8IwFIb%2FytL7raN8DBogQbmQBANh6IU3pHZn0mRrZ09r8N%2B7DaYYI1fN%2BXifnvO2UxRlUfGFd0e9g3cP6IJTWWjkbWFGvNXcCFTItSgBuZM8XTyuOYtiXlnjjDQFuZLcVghEsE4ZTYLVckYOojfuj%2BN80k8mw9FAJHksxBjEUCb9PMlhlDelTPbjEQmewWKtnJEaVMsRPaw0OqFdnYpZHPZY2BvsWczZhLPhCwmW9TZKC9eqjs5VyClVWRU5UXopI8h8E9J6j1wVQJsxGd1BpixIR9N0Q4JFN%2FG90ehLsCnYDyXhabf%2BYSKaBiaFR2ippcl8AVF1rGhjCsXzyUIhsc123Yf67tMnCbYXK%2B%2BUzpR%2Bu%2B3i67kJ%2BcN%2Bvw23m3RP5tOGz1tX7PzfubCa0uvG6fn5U2mqGtiFl48AdrWco3IgjQXeSX%2BXu9w3gf79UPMv proxyname: (null) proxyport: 0, referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345373 2020] [proxy_fcgi:debug] [pid 2292570:tid 140470009173760] mod_proxy_fcgi.c(1024): [client 10.254.0.2:58798] AH01077: declining URL http://localhost:8080/idp/profile/SAML2/Redirect/SSO?SAMLRequest=fZJdT8IwFIb%2FytL7raN8DBogQbmQBANh6IU3pHZn0mRrZ09r8N%2B7DaYYI1fN%2BXifnvO2UxRlUfGFd0e9g3cP6IJTWWjkbWFGvNXcCFTItSgBuZM8XTyuOYtiXlnjjDQFuZLcVghEsE4ZTYLVckYOojfuj%2BN80k8mw9FAJHksxBjEUCb9PMlhlDelTPbjEQmewWKtnJEaVMsRPaw0OqFdnYpZHPZY2BvsWczZhLPhCwmW9TZKC9eqjs5VyClVWRU5UXopI8h8E9J6j1wVQJsxGd1BpixIR9N0Q4JFN%2FG90ehLsCnYDyXhabf%2BYSKaBiaFR2ippcl8AVF1rGhjCsXzyUIhsc123Yf67tMnCbYXK%2B%2BUzpR%2Bu%2B3i67kJ%2BcN%2Bvw23m3RP5tOGz1tX7PzfubCa0uvG6fn5U2mqGtiFl48AdrWco3IgjQXeSX%2BXu9w3gf79UPMv, referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345379 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(2312): AH00942: HTTP: has acquired connection for (localhost)
[Mon Dec 14 14:29:25.345383 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(2365): [client 10.254.0.2:58798] AH00944: connecting http://localhost:8080/idp/profile/SAML2/Redirect/SSO?SAMLRequest=fZJdT8IwFIb%2FytL7raN8DBogQbmQBANh6IU3pHZn0mRrZ09r8N%2B7DaYYI1fN%2BXifnvO2UxRlUfGFd0e9g3cP6IJTWWjkbWFGvNXcCFTItSgBuZM8XTyuOYtiXlnjjDQFuZLcVghEsE4ZTYLVckYOojfuj%2BN80k8mw9FAJHksxBjEUCb9PMlhlDelTPbjEQmewWKtnJEaVMsRPaw0OqFdnYpZHPZY2BvsWczZhLPhCwmW9TZKC9eqjs5VyClVWRU5UXopI8h8E9J6j1wVQJsxGd1BpixIR9N0Q4JFN%2FG90ehLsCnYDyXhabf%2BYSKaBiaFR2ippcl8AVF1rGhjCsXzyUIhsc123Yf67tMnCbYXK%2B%2BUzpR%2Bu%2B3i67kJ%2BcN%2Bvw23m3RP5tOGz1tX7PzfubCa0uvG6fn5U2mqGtiFl48AdrWco3IgjQXeSX%2BXu9w3gf79UPMv to localhost:8080, referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345388 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(2574): [client 10.254.0.2:58798] AH00947: connected /idp/profile/SAML2/Redirect/SSO?SAMLRequest=fZJdT8IwFIb%2FytL7raN8DBogQbmQBANh6IU3pHZn0mRrZ09r8N%2B7DaYYI1fN%2BXifnvO2UxRlUfGFd0e9g3cP6IJTWWjkbWFGvNXcCFTItSgBuZM8XTyuOYtiXlnjjDQFuZLcVghEsE4ZTYLVckYOojfuj%2BN80k8mw9FAJHksxBjEUCb9PMlhlDelTPbjEQmewWKtnJEaVMsRPaw0OqFdnYpZHPZY2BvsWczZhLPhCwmW9TZKC9eqjs5VyClVWRU5UXopI8h8E9J6j1wVQJsxGd1BpixIR9N0Q4JFN%2FG90ehLsCnYDyXhabf%2BYSKaBiaFR2ippcl8AVF1rGhjCsXzyUIhsc123Yf67tMnCbYXK%2B%2BUzpR%2Bu%2B3i67kJ%2BcN%2Bvw23m3RP5tOGz1tX7PzfubCa0uvG6fn5U2mqGtiFl48AdrWco3IgjQXeSX%2BXu9w3gf79UPMv to localhost:8080, referer: https://apps.cirrusidentity.com/
[Mon Dec 14 14:29:25.345608 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(3034): (111)Connection refused: AH00957: HTTP: attempt to connect to [::1]:8080 (localhost) failed
[Mon Dec 14 14:29:25.345713 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(3043): AH02824: HTTP: connection established with 127.0.0.1:8080 (localhost)
[Mon Dec 14 14:29:25.345724 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(3211): AH00962: HTTP: connection complete to [::1]:8080 (localhost)
[Mon Dec 14 14:29:25.539215 2020] [proxy:debug] [pid 2292570:tid 140470009173760] proxy_util.c(2327): AH00943: http: has released connection for (localhost)
[Mon Dec 14 14:29:25.539502 2020] [ssl:debug] [pid 2292570:tid 140470009173760] ssl_engine_io.c(1108): [client 10.254.0.2:58798] AH02001: Connection closed to child 8 with standard shutdown (server idm-shib1-test.tamucc.edu:443)
tomcat with ssl handshake debug (-Djavax.net.debug=ssl:handshake)
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|DEBUG|42|http-nio-8080-exec-8|2020-12-14 14:29:25.488 CST|SSLExtensions.java:260|Ignore, context unavailable extension: pre_shared_key
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|DEBUG|42|http-nio-8080-exec-8|2020-12-14 14:29:25.489 CST|ClientHello.java:653|Produced ClientHello handshake message (
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "ClientHello": {
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "client version" : "TLSv1.2",
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "random" : "56 64 50 A9 9A 79 1E 3D 4B BA FD 4C 68 0B 88 D4 D3 EB 40 3E 4D 70 BE 84 FF 33 52 3F EE 9B 2B 03",
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "session id" : "E9 25 EC 70 05 66 23 18 30 6D 50 EB 7B 59 15 2C 78 E9 CA 87 67 58 E7 64 62 5F BF 1C E8 1D 7A 2B",
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "cipher suites" : "[TLS_AES_128_GCM_SHA256(0x1301), TLS_AES_256_GCM_SHA384(0x1302), TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384(0xC02C), TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256(0xC02B), TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384(0xC030), TLS_RSA_WITH_AES_256_GCM_SHA384(0x009D), TLS_DHE_RSA_WITH_AES_256_GCM_SHA384(0x009F), TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256(0xC02F), TLS_RSA_WITH_AES_128_GCM_SHA256(0x009C), TLS_DHE_RSA_WITH_AES_128_GCM_SHA256(0x009E), TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384(0xC024), TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384(0xC028), TLS_RSA_WITH_AES_256_CBC_SHA256(0x003D), TLS_DHE_RSA_WITH_AES_256_CBC_SHA256(0x006B), TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA(0xC00A), TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA(0xC014), TLS_RSA_WITH_AES_256_CBC_SHA(0x0035), TLS_DHE_RSA_WITH_AES_256_CBC_SHA(0x0039), TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256(0xC023), TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256(0xC027), TLS_RSA_WITH_AES_128_CBC_SHA256(0x003C), TLS_DHE_RSA_WITH_AES_128_CBC_SHA256(0x0067), TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA(0xC009), TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA(0xC013), TLS_RSA_WITH_AES_128_CBC_SHA(0x002F), TLS_DHE_RSA_WITH_AES_128_CBC_SHA(0x0033), TLS_EMPTY_RENEGOTIATION_INFO_SCSV(0x00FF)]",
....
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: )
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|DEBUG|42|http-nio-8080-exec-8|2020-12-14 14:29:25.504 CST|Alert.java:238|Received alert message (
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "Alert": {
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "level" : "fatal",
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "description": "handshake_failure"
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: }
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: )
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|ERROR|42|http-nio-8080-exec-8|2020-12-14 14:29:25.506 CST|TransportContext.java:342|Fatal (HANDSHAKE_FAILURE): Received fatal alert: handshake_failure (
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: "throwable" : {
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
.......
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: )
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|DEBUG|42|http-nio-8080-exec-8|2020-12-14 14:29:25.506 CST|SSLSocketImpl.java:1628|close the underlying socket
Dec 14 14:29:25 idm-shib1-test.tamucc.edu server[2297317]: javax.net.ssl|DEBUG|42|http-nio-8080-exec-8|2020-12-14 14:29:25.506 CST|SSLSocketImpl.java:1647|close the SSL connection (initiative)
Thanks,
Taylor
--------------------------------
Taylor Hucker
Applications System Administrator
Texas A&M University - Corpus Christi
mailto:Taylor.Hucker at tamucc.edu
--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to users-unsubscribe at shibboleth.net
More information about the users
mailing list