error in UA-NIH federation?

Wed Nov 7 16:22:49 EST 2012

Some time ago we set up federation via InC with NIH.  Looking recently to add applications, I find that the link to our institutional login at 
https://nihlogin.nih.gov/NIHfederation/ViewFederatedUniversities.aspx has the following link:

https://idp.alaska.edu/idp/profile/SAML2/POST/SSO?shire=https://nihlogin.nih.gov/affwebservices/public/samlcc&target=https://nihlogin.nih.gov/FederationPortal/Portal.asp&providerId=https://federation.nih.gov/FederationGateway

which produces an error at our IdP ("Error decoding authentication request message"); process log indicates:

12:00:00.334 - INFO [Shibboleth-Access:73] - 20121107T210000Z|137.229.79.11|idp.alaska.edu:443|/profile/SAML2/POST/SSO|
12:00:00.335 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:343] - Error decoding authentication request message
org.opensaml.ws.message.decoder.MessageDecodingException: This message deocoder only supports the HTTP POST method

I must be mis-reading these as they appear to me superficially contradictory.

With more log detail / context:

12:16:17.250 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:159] - No session associated with session ID NTk2NzQ5Mzc3ZTE0NWJiYWVlZGI3NzRhNDFjNzc3NzA1MDQ2MDljMWIyOTc4OGM2NzNmZDQzZDlhYmE0NGY2ZQ== - session must have timed out
12:16:17.250 - INFO [Shibboleth-Access:73] - 20121107T211617Z|137.229.12.28|idp.alaska.edu:443|/profile/SAML2/POST/SSO|
12:16:17.250 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:85] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/POST/SSO
12:16:17.251 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:96] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler
12:16:17.251 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:322] - LoginContext key cookie was not present in request
12:16:17.251 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:159] - Incoming request does not contain a login context, processing as first leg of request
12:16:17.251 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:311] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST'
12:16:17.251 - DEBUG [org.opensaml.ws.message.decoder.BaseMessageDecoder:75] - Beginning to decode message from inbound transport of type: org.opensaml.ws.transport.http.HttpServletRequestAdapter
12:16:17.252 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:343] - Error decoding authentication request message
org.opensaml.ws.message.decoder.MessageDecodingException: This message deocoder only supports the HTTP POST method
	at org.opensaml.saml2.binding.decoding.HTTPPostDecoder.doDecode(HTTPPostDecoder.java:82) ~[opensaml-2.5.0.jar:na]
	at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:78) ~[openws-1.4.2.jar:na]
	at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:69) ~[opensaml-2.5.0.jar:na]
	at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:331) [shibboleth-identityprovider-2.3.0.jar:na]
	at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:189) [shibboleth-identityprovider-2.3.0.jar:na]
	at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:160) [shibboleth-identityprovider-2.3.0.jar:na]
	at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:87) [shibboleth-identityprovider-2.3.0.jar:na]
	at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83) [shibboleth-common-1.3.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.32]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.32]
	at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:49) [shibboleth-identityprovider-2.3.0.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.32]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.32]
	at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:80) [shibboleth-identityprovider-2.3.0.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.32]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.32]
	at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:51) [shibboleth-common-1.3.0.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.32]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.32]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.32]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.32]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.32]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina.jar:6.0.32]
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:554) [catalina.jar:6.0.32]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.32]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina.jar:6.0.32]
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859) [tomcat-coyote.jar:6.0.32]
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588) [tomcat-coyote.jar:6.0.32]
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote.jar:6.0.32]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_29]
12:16:17.314 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:159] - No session associated with session ID NTk2NzQ5Mzc3ZTE0NWJiYWVlZGI3NzRhNDFjNzc3NzA1MDQ2MDljMWIyOTc4OGM2NzNmZDQzZDlhYmE0NGY2ZQ== - session must have timed out
12:16:17.313 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:159] - No session associated with session ID NTk2NzQ5Mzc3ZTE0NWJiYWVlZGI3NzRhNDFjNzc3NzA1MDQ2MDljMWIyOTc4OGM2NzNmZDQzZDlhYmE0NGY2ZQ== - session must have timed out

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20121107/22da7f1b/attachment-0001.html 