01:31:05.855 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:32:14.435 - INFO [Shibboleth-Access:73] - 20150625T053214Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:32:14.436 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:32:14.436 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:32:14.787 - INFO [Shibboleth-Access:73] - 20150625T053214Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:32:14.787 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:32:14.787 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:33:00.050 - INFO [Shibboleth-Access:73] - 20150625T053300Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:33:00.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:33:00.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:33:24.957 - INFO [Shibboleth-Access:73] - 20150625T053324Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:33:24.958 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:33:24.958 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:33:25.095 - INFO [Shibboleth-Access:73] - 20150625T053325Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:33:25.095 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:33:25.095 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:33:25.984 - INFO [Shibboleth-Access:73] - 20150625T053325Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:33:25.984 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:33:25.985 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:33:27.051 - INFO [Shibboleth-Access:73] - 20150625T053327Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:33:27.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:33:27.052 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:34:35.378 - INFO [Shibboleth-Access:73] - 20150625T053435Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:34:35.379 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:34:35.379 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:34:35.599 - INFO [Shibboleth-Access:73] - 20150625T053435Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:34:35.599 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:34:35.599 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:35:46.976 - INFO [Shibboleth-Access:73] - 20150625T053546Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:35:46.976 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:35:46.977 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:35:47.152 - INFO [Shibboleth-Access:73] - 20150625T053547Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:35:47.152 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:35:47.152 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:36:59.265 - INFO [Shibboleth-Access:73] - 20150625T053659Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:36:59.266 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:36:59.266 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:36:59.376 - INFO [Shibboleth-Access:73] - 20150625T053659Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:36:59.376 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:36:59.376 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:02.051 - INFO [Shibboleth-Access:73] - 20150625T053802Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:38:02.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:38:02.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:10.013 - INFO [Shibboleth-Access:73] - 20150625T053810Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:38:10.013 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:38:10.013 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:10.225 - INFO [Shibboleth-Access:73] - 20150625T053810Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:38:10.225 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:38:10.225 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:29.050 - INFO [Shibboleth-Access:73] - 20150625T053829Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:38:29.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:38:29.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:34.112 - INFO [Shibboleth-Access:73] - 20150625T053834Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:38:34.112 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:38:34.112 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:38:36.269 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:180] - No session associated with session ID 956bd3dff094a06f49bec6d92d80500bb7fe66c381e612c284744ef4813ce5df - session must have timed out 01:38:36.270 - INFO [Shibboleth-Access:73] - 20150625T053836Z|73.14.180.199|idp.testshib.org:443|/profile/SAML2/POST/SSO| 01:38:36.270 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/POST/SSO 01:38:36.270 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler 01:38:36.270 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:339] - LoginContext key cookie was not present in request 01:38:36.270 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:188] - Incoming request does not contain a login context, processing as first leg of request 01:38:36.270 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:366] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST' 01:38:36.271 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:400] - Error decoding authentication request message org.opensaml.ws.message.decoder.MessageDecodingException: This message decoder only supports the HTTP POST method at org.opensaml.saml2.binding.decoding.HTTPPostDecoder.doDecode(HTTPPostDecoder.java:83) ~[opensaml-2.6.0.jar:na] at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:79) ~[openws-1.5.0.jar:na] at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:70) ~[opensaml-2.6.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:386) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:211) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:189) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:90) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83) [shibboleth-common-1.4.0.jar:na] at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.36] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:470) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.36] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.36] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.36] at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898) [tomcat-coyote.jar:6.0.36] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:6.0.36] at java.lang.Thread.run(Thread.java:745) [na:1.7.0_55] 01:38:36.493 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:180] - No session associated with session ID 956bd3dff094a06f49bec6d92d80500bb7fe66c381e612c284744ef4813ce5df - session must have timed out 01:39:20.656 - INFO [Shibboleth-Access:73] - 20150625T053920Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:39:20.656 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:39:20.656 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:39:20.864 - INFO [Shibboleth-Access:73] - 20150625T053920Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:39:20.864 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:39:20.864 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:40:32.261 - INFO [Shibboleth-Access:73] - 20150625T054032Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:40:32.261 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:40:32.261 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:40:32.474 - INFO [Shibboleth-Access:73] - 20150625T054032Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:40:32.474 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:40:32.474 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:41:42.867 - INFO [Shibboleth-Access:73] - 20150625T054142Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:41:42.867 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:41:42.867 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:41:45.672 - INFO [Shibboleth-Access:73] - 20150625T054145Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:41:45.673 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:41:45.673 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:42:53.843 - INFO [Shibboleth-Access:73] - 20150625T054253Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:42:53.843 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:42:53.843 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:42:55.640 - INFO [Shibboleth-Access:73] - 20150625T054255Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:42:55.641 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:42:55.641 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:43:04.051 - INFO [Shibboleth-Access:73] - 20150625T054304Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:43:04.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:43:04.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:43:31.050 - INFO [Shibboleth-Access:73] - 20150625T054331Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:43:31.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:43:31.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:43:35.449 - INFO [Shibboleth-Access:73] - 20150625T054335Z|140.224.93.176|idp.testshib.org:443|/profile/SAML2/Redirect/SSO| 01:43:35.449 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/Redirect/SSO 01:43:35.449 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler 01:43:35.449 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:339] - LoginContext key cookie was not present in request 01:43:35.449 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:188] - Incoming request does not contain a login context, processing as first leg of request 01:43:35.449 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:366] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect' 01:43:35.452 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128] - Looking up relying party configuration for https://we.love.cheetos/om/nom 01:43:35.453 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:134] - No custom relying party configuration found for https://we.love.cheetos/om/nom, looking up configuration based on metadata groups. 01:43:35.453 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:157] - No custom or group-based relying party configuration found for https://we.love.cheetos/om/nom. Using default relying party configuration. 01:43:35.453 - WARN [org.opensaml.saml2.binding.security.SAML2AuthnRequestsSignedRule:81] - SPSSODescriptor role metadata for entityID 'https://we.love.cheetos/om/nom' could not be resolved 01:43:35.454 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:387] - Decoded request from relying party 'https://we.love.cheetos/om/nom' 01:43:35.454 - WARN [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:305] - No metadata for relying party https://we.love.cheetos/om/nom, treating party as anonymous 01:43:35.454 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:222] - SAML 2 SSO profile is not configured for relying party https://we.love.cheetos/om/nom 01:43:42.243 - INFO [Shibboleth-Access:73] - 20150625T054342Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:43:42.244 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:43:42.244 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:44:03.478 - INFO [Shibboleth-Access:73] - 20150625T054403Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:44:03.478 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:44:03.479 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:44:04.379 - INFO [Shibboleth-Access:73] - 20150625T054404Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:44:04.379 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:44:04.379 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:45:13.233 - INFO [Shibboleth-Access:73] - 20150625T054513Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:45:13.233 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:45:13.233 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:45:13.708 - INFO [Shibboleth-Access:73] - 20150625T054513Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:45:13.708 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:45:13.708 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:46:22.565 - INFO [Shibboleth-Access:73] - 20150625T054622Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:46:22.566 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:46:22.566 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:46:23.149 - INFO [Shibboleth-Access:73] - 20150625T054623Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:46:23.150 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:46:23.150 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:47:32.388 - INFO [Shibboleth-Access:73] - 20150625T054732Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:47:32.388 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:47:32.389 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:47:32.639 - INFO [Shibboleth-Access:73] - 20150625T054732Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:47:32.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:47:32.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:48:06.051 - INFO [Shibboleth-Access:73] - 20150625T054806Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:48:06.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:48:06.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:48:33.050 - INFO [Shibboleth-Access:73] - 20150625T054833Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:48:33.050 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:48:33.050 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:48:41.892 - INFO [Shibboleth-Access:73] - 20150625T054841Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:48:41.892 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:48:41.892 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:48:42.115 - INFO [Shibboleth-Access:73] - 20150625T054842Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:48:42.115 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:48:42.115 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:48:49.034 - INFO [Shibboleth-Access:73] - 20150625T054849Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:48:49.034 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:48:49.034 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:49:51.547 - INFO [Shibboleth-Access:73] - 20150625T054951Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:49:51.547 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:49:51.547 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:49:52.117 - INFO [Shibboleth-Access:73] - 20150625T054952Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:49:52.117 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:49:52.117 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:51:03.005 - INFO [Shibboleth-Access:73] - 20150625T055103Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:51:03.006 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:51:03.006 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:51:03.183 - INFO [Shibboleth-Access:73] - 20150625T055103Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:51:03.183 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:51:03.183 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:52:13.693 - INFO [Shibboleth-Access:73] - 20150625T055213Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:52:13.694 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:52:13.694 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:52:13.920 - INFO [Shibboleth-Access:73] - 20150625T055213Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:52:13.920 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:52:13.920 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:53:08.050 - INFO [Shibboleth-Access:73] - 20150625T055308Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:53:08.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:53:08.051 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:53:22.923 - INFO [Shibboleth-Access:73] - 20150625T055322Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:53:22.923 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:53:22.924 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:53:23.118 - INFO [Shibboleth-Access:73] - 20150625T055323Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:53:23.118 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:53:23.118 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:53:35.050 - INFO [Shibboleth-Access:73] - 20150625T055335Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:53:35.050 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:53:35.050 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:53:57.492 - INFO [Shibboleth-Access:73] - 20150625T055357Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:53:57.493 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:53:57.493 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:54:31.234 - INFO [Shibboleth-Access:73] - 20150625T055431Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:54:31.234 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:54:31.234 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:54:32.066 - INFO [Shibboleth-Access:73] - 20150625T055432Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:54:32.066 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:54:32.066 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:55:42.089 - INFO [Shibboleth-Access:73] - 20150625T055542Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:55:42.090 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:55:42.090 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:55:42.230 - INFO [Shibboleth-Access:73] - 20150625T055542Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:55:42.230 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:55:42.231 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:56:51.504 - INFO [Shibboleth-Access:73] - 20150625T055651Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:56:51.504 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:56:51.505 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:56:51.680 - INFO [Shibboleth-Access:73] - 20150625T055651Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:56:51.680 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:56:51.680 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:58:02.626 - INFO [Shibboleth-Access:73] - 20150625T055802Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:58:02.627 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:58:02.627 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:58:02.919 - INFO [Shibboleth-Access:73] - 20150625T055802Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:58:02.919 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:58:02.919 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:58:10.055 - INFO [Shibboleth-Access:73] - 20150625T055810Z|54.174.140.185|idp.testshib.org:443|/profile/Metadata/SAML| 01:58:10.055 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:58:10.055 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:58:37.055 - INFO [Shibboleth-Access:73] - 20150625T055837Z|54.85.254.104|idp.testshib.org:443|/profile/Metadata/SAML| 01:58:37.055 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:58:37.056 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:59:07.129 - INFO [Shibboleth-Access:73] - 20150625T055907Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:59:07.130 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:59:07.130 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:59:09.262 - INFO [Shibboleth-Access:73] - 20150625T055909Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:59:09.262 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:59:09.262 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:59:12.119 - INFO [Shibboleth-Access:73] - 20150625T055912Z|208.83.125.234|idp.testshib.org:443|/profile/Metadata/SAML| 01:59:12.120 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /Metadata/SAML 01:59:12.120 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.SAMLMetadataProfileHandler 01:59:31.934 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:180] - No session associated with session ID 956bd3dff094a06f49bec6d92d80500bb7fe66c381e612c284744ef4813ce5df - session must have timed out 01:59:31.934 - INFO [Shibboleth-Access:73] - 20150625T055931Z|73.14.180.199|idp.testshib.org:443|/profile/SAML2/POST/SSO| 01:59:31.935 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/POST/SSO 01:59:31.935 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler 01:59:31.935 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:339] - LoginContext key cookie was not present in request 01:59:31.935 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:188] - Incoming request does not contain a login context, processing as first leg of request 01:59:31.935 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:366] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST' 01:59:31.935 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:400] - Error decoding authentication request message org.opensaml.ws.message.decoder.MessageDecodingException: This message decoder only supports the HTTP POST method at org.opensaml.saml2.binding.decoding.HTTPPostDecoder.doDecode(HTTPPostDecoder.java:83) ~[opensaml-2.6.0.jar:na] at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:79) ~[openws-1.5.0.jar:na] at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:70) ~[opensaml-2.6.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:386) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:211) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:189) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:90) [shibboleth-identityprovider-2.4.0.jar:na] at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83) [shibboleth-common-1.4.0.jar:na] at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.0.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.36] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:470) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.36] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.36] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.36] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.36] at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705) [tomcat-coyote.jar:6.0.36] at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898) [tomcat-coyote.jar:6.0.36] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:6.0.36] at java.lang.Thread.run(Thread.java:745) [na:1.7.0_55] 01:59:32.410 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:180] - No session associated with session ID 956bd3dff094a06f49bec6d92d80500bb7fe66c381e612c284744ef4813ce5df - session must have timed out