How to Debug?
Ivan Dolezal
Hi,
my installation of IdP SimpleSAML 1.6.2 is working just fine with a
few well-established SP's (at other universities) except for one. When I
want to use it, instead of being redirected to Login/Password page I get
immediately the error screen:
Exception: Unable to find the current binding.
0: /var/simplesamlphp-1.6.2/lib/SAML2/Binding.php:72
(SAML2_Binding::getCurrentBinding)
1: /var/simplesamlphp-1.6.2/modules/saml/lib/IdP/SAML2.php:229
(sspmod_saml_IdP_SAML2::receiveAuthnRequest)
2: /var/simplesamlphp-1.6.2/www/saml2/idp/SSOService.php:19 (N/A)
URL:
https://idptoo.osu.cz/simplesaml/saml2/idp/SSOService.php
Track ID:
4e95176689
Version: 1.6.2
Report ID: 1a66073b
This is not of more help:
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
/simplesaml/saml2/idp/SSOService.php - UserError:
ErrCode:UNHANDLEDEXCEPTION: Unable+to+find+the+current+binding.
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
Exception: Exception
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
Backtrace:
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
0: /var/simplesamlphp-1.6.2/lib/SAML2/Binding.php:72
(SAML2_Binding::getCurrentBinding)
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
1: /var/simplesamlphp-1.6.2/modules/saml/lib/IdP/SAML2.php:229
(sspmod_saml_IdP_SAML2::receiveAuthnRequest)
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
2: /var/simplesamlphp-1.6.2/www/saml2/idp/SSOService.php:19 (N/A)
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3
[4e95176689]
/var/log/messages:May 17 09:35:15 simplesamlphp[82515]: 3 [4e95176689]
Error report with id 1a66073b generated.
May 17 09:35:15 simplesamlphp[82515]: 7 [4e95176689] Processing
config.php
May 17 09:35:15 simplesamlphp[82515]: 7 [4e95176689] Processing
config.php
May 17 09:35:15 simplesamlphp[82515]: 7 [4e95176689] Template: Reading
[/var/simplesamlphp-1.6.2/dictionaries/errors]
May 17 09:35:35 simplesamlphp[64421]: 7 [4e95176689] Processing
config.php
May 17 09:35:35 simplesamlphp[64421]: 7 [4e95176689] Processing
config.php
May 17 09:35:35 simplesamlphp[64421]: 7 [4e95176689] Processing
config.php
May 17 09:35:35 simplesamlphp[64421]: 7 [4e95176689] Processing
config.php
May 17 09:35:35 simplesamlphp[64421]: 7 [4e95176689] Template: Reading
[/var/simplesamlphp-1.6.2/dictionaries/errors]
May 17 09:35:55 simplesamlphp[48824]: 7 [4e95176689] Processing
config.php
May 17 09:35:55 simplesamlphp[48824]: 7 [4e95176689] Processing
config.php
May 17 09:35:55 simplesamlphp[48824]: 7 [4e95176689] Template: Reading
[/var/simplesamlphp-1.6.2/dictionaries/errors]
May 17 09:39:06 simplesamlphp[48468]: 7 [4e95176689] Processing
config.php
May 17 09:39:06 simplesamlphp[48468]: 7 [4e95176689] Processing
config.php
May 17 09:39:06 simplesamlphp[48468]: 7 [4e95176689] Template: Reading
[/var/simplesamlphp-1.6.2/dictionaries/errors]
1. How can I actually improve the verbosity so that I can read some
more ?
2. Is this error something familiar? I couldn't Google anything and I
am currently quite busy with other completely different urgent tasks
:-(
Thank you VERY KINDLY for any help!
--
Ing. Ivan Doležal
Centrum informačních technologií
Ostravská univerzita v Ostravě
Bráfova 5, kancelář 204
701 03 Ostrava
gsm 739 386 565
tel 59 709 1158
tel 59 709 5003
fax 596 120 481
Peter Schober
> Exception: Unable to find the current binding.
You could grab at the authentication request from the SP (e.g. from
your webserver's logs or via transit from the webbrowser) and feed it
to saml2debug (on your IdP or the public one by Andreas, as found by
$SEARCHENGINE).
Also you could check the metadata for the SP in question to make sure
it uses protocol bindings your IdP supports.
Can't help with debug logging atm,
-peter
Olav Morken
>
> 1. How can I actually improve the verbosity so that I can read some
> more ?
I don't think anything else relevant will be logged for this error.
> 2. Is this error something familiar? I couldn't Google anything and I
> am currently quite busy with other completely different urgent tasks
> :-(
Any chance that the IdP is running Debian Squeeze (or otherwise has the
Suhosin PHP extension installed)? That extension has been known to
result in the error you see.
If it turns out that the IdP is using that extension, you should
increase the value of suhosin.get.max_value_length:
http://www.hardened-php.net/suhosin/configuration.html#suhosin.get.max_value_length
Increasing it to 2048 bytes should be enough.
Regards,
Olav Morken
UNINETT / Feide
Ivan Dolezal
Hi again,
yes, IdP is running on top of FreeBSD, Apache with Suhosin
installed.
However, I had verified (based on similarity with some other case in
SimpleSAMLphp archive) that
http://idptoo.osu.cz/strlen.php?xxxx=AA...A # perl -e 'print
"A"x2050;'
<?php echo strlen($_REQUEST["xxxx"]); ?>
made it all the way in.
Turning it off completely by
[suhosin]
; Misc Options
suhosin.simulation = On
in /usr/local/lib/php.ini and restarting Apache didn't help either.
Olav Morken
In that case you need to add more debug code to the getCurrentBinding()
function in lib/SAML2/Binding.php, to try to narrow down the problem.
I suggest logging at least $_SERVER['REQUEST_METHOD'] and
array_keys($_REQUEST).
Ivan Dolezal
Hi again, what I got is:
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST_METHOD GET
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[shire]=https://netis.vsb.cz/Shibboleth.sso/SAML/POST
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[time]=1305812192
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[target]=cookie:eb20c8ea
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[providerId]=https://netis.vsb.cz/sp/shibboleth
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[__utma]=180545849.584364521.1260023998.1270540278.1287061971.26
May 19 15:49:03 foreman simplesamlphp[16499]: 7 [fcd6267776]
REQUEST[PHPSESSID]=f28fe27c53aaad82969c551f513c3197
thus obviously not finding neither SAMLRequest, SAMLResponse, SAMLart
:-( Now I am getting lost... is this correct?
Thank you VERY MUCH for your patience!
Olav Morken
This isn't a SAML 2.0 authentication request, but a SAML 1.1
authentication request (more specifically, it is a "urn:mace:shibboleth:
1.0:profiles:AuthnRequest").
It appears that either the IdP metadata is listed incorretly, so that
its SAML 2.0 SingleSignOnService element is listed as supporting the
SAML 1.1 protocol, or the SP ignores the supported protocols and
bindings for the IdP, and thus ends up sending an invalid
authentication request to the IdP.