Shibboleth SP3 Problem: xmltooling::IOException setHeader (Header) failed: -2147024809

[Stephen Holland-Chang]

We are using Shibboleth SP 3 (v. 3.1.0.2) on Windows 2019 Server / IIS with Adobe Coldfusion 2018. 

Most users have no problems logging in, but recently have had a handful of people show this error after they try to come back to our Application from the Login:

---------------

xmltooling::IOException

The system encountered an error at Wed Jan 13 16:30:23 2021 

To report this problem, please contact the site administrator : [hidden email]

Please include the following in any email:

xmltooling::IOException at (https://xxx/sso.index.cfm)

setHeader (Header) failed: -2147024809

---------------

I cant seem to find anything matching the setHeader error online. 

The error happens for them in Chrome or Safari. 

I have enabled DEBUG logging and in my shibd.log matching the exact time with the user who cannot login and it does not show any errors but a successful session created:

2021-01-13 16:30:23 INFO Shibboleth.SessionCache [1] [default]: new session created: ID (_073dd023bc2583df7a05ce9725a7dba2) IdP (http://xxxxxxxx) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address (xx.xx.xx.xx)

Based on the error is Shibboleth having setting the headers? Could there be something on the user end that would prevent that? (Security software?)

In my Shibboleth2.xml file I have:

<ISAPI normalizeRequest="true" useHeaders="true" safeHeaderNames="true”>

Our application does use Request headers to pass SAML attributes from the IDP back to our server. I understand this is not the best way to handle it but this is how we were doing it with Shibboleth 2 and never could figure out how to get CGI variables to show up from the IDP. 

I would appreciate if anyone has any information on this or could offer help here. 

Thanks so much!

Stephen 

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

That's an E_INVALIDARG code, and I have never heard of it happening, those error checks are practically cosmetic. My guess is the attribute data that was decoded and eventually passed through is unusual in some way if it's reproducible.

The only parameters are the header name, which is obvious fixed, the data, and the length. That doesn't leave much to be invalid.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Stephen Holland-Chang]

Thanks Scott, is there anyway to bypass this error or log the full list i attributes passed so we can see whats wrong?

> On Jan 13, 2021, at 6:01 PM, Cantor, Scott <[hidden email]> wrote:
>
> That's an E_INVALIDARG code, and I have never heard of it happening, those error checks are practically cosmetic. My guess is the attribute data that was decoded and eventually passed through is unusual in some way if it's reproducible.
>
> The only parameters are the header name, which is obvious fixed, the data, and the length. That doesn't leave much to be invalid.
>
> -- Scott
>
>
> --
> For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
> To unsubscribe from this list send an email to [hidden email]

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

On 1/13/21, 9:26 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

>    Thanks Scott, is there anyway to bypass this error or log the full list i attributes passed so we can see whats wrong?

Logging documentation and configuration addresses what categories log SAML messages.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Stephen Holland-Chang]

Ive looked at the log configuration guide for Shibboleth SP 3 but still cannot see anywhere in logs to show me which SAML2 data that keeps failing.

Looking in the Windows Event Logger under Shibboleth it doesn’t show any WARN or ERRORS

When Shibboleth errors with that xmltooling::IOException, shouldn’t it be logging that error somewhere? Any guidance to help us so we can track down the data that is throwing the error would be greatly appreciated!

---
We have configured our native.logger to DEBUG

# set overall behavior
log4j.rootCategory=DEBUG, native_log

# fairly verbose for DEBUG, so generally leave at WARN/INFO
log4j.category.XMLTooling.XMLObject=DEBUG
log4j.category.XMLTooling.XMLObjectBuilder=WARN
log4j.category.XMLTooling.KeyInfoResolver=WARN
log4j.category.Shibboleth.IPRange=WARN
log4j.category.Shibboleth.PropertySet=WARN

# raise for low-level tracing of SOAP client HTTP/SSL behavior
log4j.category.XMLTooling.libcurl=WARN

# useful categories to tune independently:
# tracing of SAML messages and security policies
log4j.category.OpenSAML.MessageDecoder=DEBUG
log4j.category.OpenSAML.MessageEncoder=DEBUG

log4j.appender.native_log=org.apache.log4j.NTEventLogAppender
log4j.appender.native_log.source=Shibboleth Service Provider
log4j.appender.native_log.layout=org.apache.log4j.PatternLayout
log4j.appender.native_log.layout.ConversionPattern=%c %x: %m
--

Thanks!

> On Jan 13, 2021, at 6:28 PM, Cantor, Scott <[hidden email]> wrote:
>
> On 1/13/21, 9:26 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:
>
>>   Thanks Scott, is there anyway to bypass this error or log the full list i attributes passed so we can see whats wrong?
>
> Logging documentation and configuration addresses what categories log SAML messages.
>
> -- Scott
>
>
> --
> For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
> To unsubscribe from this list send an email to [hidden email]

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

On 1/14/21, 3:06 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

>    Ive looked at the log configuration guide for Shibboleth SP 3 but still cannot see anywhere in logs to show me which
> SAML2 data that keeps failing.

The part that tells you to use shibd.log for anything important, which is configured by shibd.logger.

However I would say the native.logger file is long broken, most of the categories in it are only in the other log file so they're misleading by including them there.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Stephen Holland-Chang]

Thanks for helping me understand the logger better. That worked and I found out that the decrypted attributes being passed are prepended with a value which includes a backslash. 

For example:

<AttributeValue>corp\examplevalue</AttributeValue>

Could the \ be causing problems with Shibboleth setting the data into the request header? If so, are there any options for escaping that in Shibboleth?

Thanks for the help!

Stephen 

On Jan 14, 2021, at 12:09 PM, Cantor, Scott <[hidden email]> wrote:

On 1/14/21, 3:06 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

  Ive looked at the log configuration guide for Shibboleth SP 3 but still cannot see anywhere in logs to show me which
SAML2 data that keeps failing.

The part that tells you to use shibd.log for anything important, which is configured by shibd.logger.

However I would say the native.logger file is long broken, most of the categories in it are only in the other log file so they're misleading by including them there.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Stephen Holland-Chang]

What is strange about this is that looking at the DEBUG logs Shibboleth does not throw an error or anything it looks like its processing everything fine. 

Session is created and all the attributes we need look to be decrypted and set properly. The user is redirected:

2021-01-14 16:07:12 DEBUG Shibboleth.SSO.SAML2 [1] [default]: ACS returning via redirect to: https://xx/sso/index.cfm

But the user then see that xmltooling::IOException error when it tries to hit that Shibboleth protected page https://xx/sso/index.cfm

Is that  error thrown by Shibboleth? 

Stephen

On Jan 14, 2021, at 4:28 PM, Stephen Holland-Chang <[hidden email]> wrote:

Thanks for helping me understand the logger better. That worked and I found out that the decrypted attributes being passed are prepended with a value which includes a backslash. 

For example:

<AttributeValue>corp\examplevalue</AttributeValue>

Could the \ be causing problems with Shibboleth setting the data into the request header? If so, are there any options for escaping that in Shibboleth?

Thanks for the help!

Stephen 

On Jan 14, 2021, at 12:09 PM, Cantor, Scott <[hidden email]> wrote:

On 1/14/21, 3:06 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

  Ive looked at the log configuration guide for Shibboleth SP 3 but still cannot see anywhere in logs to show me which
SAML2 data that keeps failing.

The part that tells you to use shibd.log for anything important, which is configured by shibd.logger.

However I would say the native.logger file is long broken, most of the categories in it are only in the other log file so they're misleading by including them there.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

On 1/14/21, 7:28 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

>    Could the \ be causing problems with Shibboleth setting the data into the request header? If so, are there any options
> for escaping that in Shibboleth?

I wouldn't think so but I have no idea what IIS cares about.

You could try applying a Transform AttributeResolver [1] with a regex to detect and replace the backslash as a test of whether it makes a difference or not.

-- Scott

[1] https://wiki.shibboleth.net/confluence/display/SP3/TransformAttributeResolver


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

On 1/14/21, 7:39 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

>    What is strange about this is that looking at the DEBUG logs Shibboleth does not throw an error or anything it looks like
> its processing everything fine.

There's nothing wrong with that data. If the problem is IIS and the SetHeader API, that's not going to matter until a request is processed that requires attaching the header.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Stephen Holland-Chang]

Ah ok thanks, looking at the data closer, I believe the issue could be with the length of the attribute values as they are quite long.

I increased the Content-Length of IIS Request Filtering to allow for larger headers and will see if that does the trick. Appreciate the help and will post back if that was the issue.

S

Stephen Holland-Chang

On Jan 14, 2021, at 4:49 PM, Cantor, Scott <[hidden email]> wrote:

On 1/14/21, 7:39 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

  What is strange about this is that looking at the DEBUG logs Shibboleth does not throw an error or anything it looks like
its processing everything fine.

There's nothing wrong with that data. If the problem is IIS and the SetHeader API, that's not going to matter until a request is processed that requires attaching the header.

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

[Cantor, Scott E.]

On 1/14/21, 8:11 PM, "users on behalf of Stephen Holland-Chang" <[hidden email] on behalf of [hidden email]> wrote:

>    Ah ok thanks, looking at the data closer, I believe the issue could be with the length of the attribute values as they are
> quite long.

That is the most obvious risk, but how long are we talking? That is not a normal thing for an IdP to do.

>I increased the Content-Length of IIS Request Filtering to allow for larger headers and will see if that does the trick.

Can you outline where/what setting it is so I can document it?

-- Scott


--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]