Shibboleth Developers

["Mahabalagiri, Datta" <>]

Hi,

I noticed this error in my logs. I haven't reproduced yet. I suspect it 
happens under moderate to heavy load. 
I pulled up mailing lists, found a similar problem that some one reported 
last year (see below). Did it resurface? 
I truncated some of the logs.

2010-09-21-00:35:25.681 ERROR   Encountered error parsing message into its 
DOM representation
org.opensaml.xml.parse.XMLParserException: Unable to read XML from input 
stream
        at 
org.opensaml.xml.parse.BasicParserPool.parse(BasicParserPool.java:221) 
[xmltooling-1.3.0.jar:na]
        at 
org.opensaml.ws.message.decoder.BaseMessageDecoder.unmarshallMessage(BaseMessageDecoder.java:164)
 [openws-1.4.0.jar:na]
        at 
org.opensaml.saml1.binding.decoding.HTTPSOAP11Decoder.doDecode(HTTPSOAP11Decoder.java:143)
 [opensaml-2.4.0.jar:na]
        at 
org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:75)
 [openws-1.4.0.jar:na]
        at 
org.opensaml.saml1.binding.decoding.BaseSAML1MessageDecoder.decode(BaseSAML1MessageDecoder.java:108)
 [opensaml-2.4.0.jar:na]
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.decodeRequest(AttributeQueryProfileHandler.java:157)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.processRequest(AttributeQueryProfileHandler.java:80)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.processRequest(AttributeQueryProfileHandler.java:1)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
..
        at 
org.opensaml.xml.parse.BasicParserPool$DocumentBuilderProxy.parse(BasicParserPool.java:643)
 [xmltooling-1.3.0.jar:na]
        at 
org.opensaml.xml.parse.BasicParserPool.parse(BasicParserPool.java:216) 
[xmltooling-1.3.0.jar:na]
        ... 35 common frames omitted
2010-09-21-00:35:25.683 WARN   Error decoding attribute query message
org.opensaml.ws.message.decoder.MessageDecodingException: Encountered error 
parsing message into its DOM representation
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.decodeRequest(AttributeQueryProfileHandler.java:157)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.processRequest(AttributeQueryProfileHandler.java:80)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
        at 
edu.internet2.middleware.shibboleth.idp.profile.saml1.AttributeQueryProfileHandler.processRequest(AttributeQueryProfileHandler.java:1)
 [shibboleth-identityprovider-2.2.0-SNAPSHOT.jar:na]
        at 
edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83)
 [shibboleth-common-1.2.0.jar:na]
..
..
        at java.lang.Thread.run(Thread.java:619) [na:1.6.0_13]
Caused by: org.opensaml.xml.parse.XMLParserException: Unable to read XML from 
input stream
        at 
org.opensaml.xml.parse.BasicParserPool.parse(BasicParserPool.java:221) 
[xmltooling-1.3.0.jar:na]
        at 
org.opensaml.ws.message.decoder.BaseMessageDecoder.unmarshallMessage(BaseMessageDecoder.java:164)
 [openws-1.4.0.jar:na]
        ... 34 common frames omitted
Caused by: java.io.IOException: null
        at org.apache.jk.common.JkInputStream.receive(JkInputStream.java:199) 
[tomcat-coyote.jar:na]
        at 
org.apache.jk.common.JkInputStream.refillReadBuffer(JkInputStream.java:258) 
[tomcat-coyote.jar:na]
        at org.apache.jk.common.JkInputStream.doRead(JkInputStream.java:177) 
[tomcat-coyote.jar:na]
        at org.apache.coyote.Request.doRead(Request.java:428) 
[tomcat-coyote.jar:na]
        at 
org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:304) 
[catalina.jar:na]
..
..
        at 
org.opensaml.xml.parse.BasicParserPool$DocumentBuilderProxy.parse(BasicParserPool.java:643)
 [xmltooling-1.3.0.jar:na]
        at 
org.opensaml.xml.parse.BasicParserPool.parse(BasicParserPool.java:216) 
[xmltooling-1.3.0.jar:na]
        ... 35 common frames omitted

--Datta

From past mailing list:
-----------------------------------------------------------------------------------------------------

>> On Mon, Feb 9, 2009 at 12:32 PM, Chad La Joie 
>> <>
>>  wrote:
>>> This issue is already in JIRA.  You can see that fix that some one 
>>> proposed for this.  I'm still unable to reproduce it but every time 
>>> I look at it I become more and more convinced that this is a 
>>> threading issue somewhere inside Xerces, the XML parser in use.
>>>
>>> Adam Lantos wrote:
>>>> Hello,
>>>>
>>>>
>>>> I've performed some load-testing on our shib2 sp + shib2 idp 
>>>> (2.1.2) setup. The test scenario was pretty straightforward: access 
>>>> some protected resource at SP, then authenticate at IdP, and 
>>>> finally access the resource again.
>>>>
>>>> When more than five concurrent threads were active, the idp 
>>>> frequently throwed SAXExceptions causing authnrequest to fail. Here 
>>>> is the stacktrace from my idp-process.log:
>>>>
>>>> 11:23:49.393 ERROR
>>>> [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHa
>>>> ndler:317]
>>>> - Error decoding
>>>> authentication request message
>>>> org.opensaml.ws.message.decoder.MessageDecodingException: 
>>>> Encountered error parsing message into its DOM representation
>>>>         at 
>>>> org.opensaml.ws.message.decoder.BaseMessageDecoder.unmarshallMessag
>>>> e(BaseMessageDecoder.java:166)
>>>> [open
>>>> ws-1.2.2.jar:na]
>>>>         at 
>>>> org.opensaml.saml2.binding.decoding.HTTPRedirectDeflateDecoder.doDe
>>>> code(HTTPRedirectDeflateDecoder.java
>>>> :105) [opensaml-2.2.3.jar:na]
>>>>         at 
>>>> org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessa
>>>> geDecoder.java:74)
>>>> [openws-1.2.2.jar
>>>> :na]
>>>>         at 
>>>> org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(
>>>> BaseSAML2MessageDecoder.java:69)
>>>> [op
>>>> ensaml-2.2.3.jar:na]
>>>>         at 
>>>> edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHan
>>>> dler.decodeRequest(SSOProfileHandler
>>>> .java:306) [shibboleth-identityprovider-2.1.2.jar:na]
>>>>         at 
..
..
>>>>
>>>>
>>>> I presume the BasicParserPool synchronizing code fails here, and 
>>>> two or more threads use the same DOMParser instance concurrently. 
>>>> But this is only a guess, so please let me know what to investigate 
>>>> further.
>>>>
>>>>
>>>> thanks,
>>>>  Adam
>>> --