null principal in attribute resolver
Daniele Russo
ruda76 at gmail.com
Tue Nov 29 13:43:59 GMT 2011
I think this is the part of log:
10:41:20.328 - INFO [Shibboleth-Access:74] -
20111128T094120Z|93.70.49.139|www.inarcassa.it:443
|/profile/SAML2/Redirect/SSO|
10:41:20.328 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86]
- shibboleth.HandlerManager: Looking up profile handler for request path:
/SAML2/Redirect/SSO
10:41:20.329 - 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
10:41:20.329 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:163]
- Incoming request contains a login context, processing as second leg of
request
10:41:20.329 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:572] -
Unbinding LoginContext
10:41:20.329 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:598] -
Expiring LoginContext cookie
10:41:20.329 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:607] -
Removing LoginContext, with key 0f036b58-d567-4517-b7ea-b6d28ca6f7a5, from
StorageService partition loginContexts
10:41:20.330 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128]
- Looking up relying party configuration for
https://www.inarcassa.it/shibboleth
10:41:20.330 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:134]
- No custom relying party configuration found for
https://www.inarcassa.it/shibboleth, looking up configuration based on
metadata groups.
10:41:20.330 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:157]
- No custom or group-based relying party configuration found for
https://www.inarcassa.it/shibboleth. Using default relying party
configuration.
10:41:20.331 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:472]
- Resolving attributes for principal 'null' for SAML request from relying
party 'https://www.inarcassa.it/shibboleth'
10:41:20.331 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:119]
- shibboleth.AttributeResolver resolving attributes for principal null
10:41:20.332 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:275]
- Specific attributes for principal null were not requested, resolving all
attributes.
10:41:20.332 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute uid for principal null
10:41:20.332 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354]
- Resolving data connector myLDAP for principal null
10:41:20.369 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:308]
- Search filter: (uid=$requestContext.principalName)
10:41:20.370 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:363]
- LDAP data connector myLDAP - Retrieving attributes from LDAP
10:41:20.373 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute uid containing 0 values
10:41:20.373 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute Profilo for principal null
10:41:20.373 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354]
- Resolving data connector regute for principal null
10:41:20.374 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:262]
- RDBMS data connector regute - Search Query: select 'ENTPEN9934' CODENT
,A.CODPIN CODPIN ,A.MAT MAT,'Cittadino' RUO ,B.CODFIS CODFIS
,DECODE(A.INDEMLPEC,NULL,A.INDEML,A.INDEMLPEC) INDEML,
GET_PROFILE(A.CODPIN) PROFILO FROM I_REGUTE A ,B_ANACAS B WHERE
B.MAT(+)=A.MAT AND CODPIN='$requestContext.principalName'
10:41:20.376 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:323]
- RDBMS data connector regute - Querying database for attributes with query
select 'ENTPEN9934' CODENT ,A.CODPIN CODPIN ,A.MAT MAT,'Cittadino' RUO
,B.CODFIS CODFIS ,DECODE(A.INDEMLPEC,NULL,A.INDEML,A.INDEMLPEC) INDEML,
GET_PROFILE(A.CODPIN) PROFILO FROM I_REGUTE A ,B_ANACAS B WHERE
B.MAT(+)=A.MAT AND CODPIN='$requestContext.principalName'
10:41:20.381 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:332]
- RDBMS data connector regute - Retrieved attributes: []
10:41:20.382 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354]
- Resolving data connector regsoc for principal null
10:41:20.382 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:262]
- RDBMS data connector regsoc - Search Query: select CODPIN ,CODSOC MAT,
DECODE(INDPECRPL,NULL,INDEMLRPL,INDPECRPL) INDEML, GET_PROFILE(CODPIN)
PROFILO FROM I_REGSOC WHERE CODPIN='$requestContext.principalName'
10:41:20.384 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:323]
- RDBMS data connector regsoc - Querying database for attributes with query
select CODPIN ,CODSOC MAT, DECODE(INDPECRPL,NULL,INDEMLRPL,INDPECRPL)
INDEML, GET_PROFILE(CODPIN) PROFILO FROM I_REGSOC WHERE
CODPIN='$requestContext.principalName'
10:41:20.387 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.RDBMSDataConnector:332]
- RDBMS data connector regsoc - Retrieved attributes: []
10:41:20.388 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute Profilo containing 0 values
10:41:20.388 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute CodiceEnte for principal null
10:41:20.388 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute CodiceEnte containing 0 values
10:41:20.388 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute Contatti for principal null
10:41:20.388 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute Contatti containing 0 values
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute CodiceFiscale for principal null
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute CodiceFiscale containing 0 values
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute Ruolo for principal null
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute Ruolo containing 0 values
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute CodiceUtente for principal null
10:41:20.389 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute CodiceUtente containing 0 values
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute Matricola for principal null
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute Matricola containing 0 values
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute uid from resolution result for principal null. It
contains no values.
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute Profilo from resolution result for principal null. It
contains no values.
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute CodiceEnte from resolution result for principal null.
It contains no values.
10:41:20.390 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute Contatti from resolution result for principal null.
It contains no values.
10:41:20.391 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute CodiceFiscale from resolution result for principal
null. It contains no values.
10:41:20.391 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute Ruolo from resolution result for principal null. It
contains no values.
10:41:20.391 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute CodiceUtente from resolution result for principal
null. It contains no values.
10:41:20.391 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute Matricola from resolution result for principal null.
It contains no values.
10:41:20.391 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:137]
- shibboleth.AttributeResolver resolved, for principal null, the
attributes: []
10:41:20.392 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:71]
- shibboleth.AttributeFilterEngine filtering 0 attributes for principal null
10:41:20.392 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:499]
- Creating attribute statement in response to SAML request
'_37239fdb6e3f76b3008ee0249f7c3518' from relying party '
https://www.inarcassa.it/shibboleth'
10:41:20.392 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:128]
- No attributes remained after encoding and filtering by value, no
attribute statement built
10:41:20.392 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:486]
- No attributes for principal 'null' support encoding into a supported name
identifier format for relying party 'https://www.inarcassa.it/shibboleth'
10:41:20.393 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:566]
- Determining if SAML assertion to relying party '
https://www.inarcassa.it/shibboleth' should be signed
10:41:20.393 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:639]
- IdP relying party configuration 'default' indicates to sign assertions:
true
10:41:20.393 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:577]
- Determining signing credntial for assertion to relying party '
https://www.inarcassa.it/shibboleth'
10:41:20.393 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:591]
- Signing assertion to relying party https://www.inarcassa.it/shibboleth
10:41:20.425 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:274]
- Attempting to encrypt assertion to relying party '
https://www.inarcassa.it/shibboleth'
10:41:20.426 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:279]
- Assertion to be encrypted is:
<?xml version="1.0" encoding="UTF-8"?><saml2:Assertion
xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion"
ID="_949f3173d3dadc49c6b480065c2f9f37"
IssueInstant="2011-11-28T09:41:20.392Z" Version="2.0">
<saml2:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">
https://www.inarcassa.it/idp/shibboleth</saml2:Issuer>
<ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#">
<ds:SignedInfo>
<ds:CanonicalizationMethod Algorithm="
http://www.w3.org/2001/10/xml-exc-c14n#"/>
<ds:SignatureMethod Algorithm="
http://www.w3.org/2000/09/xmldsig#rsa-sha1"/>
<ds:Reference URI="#_949f3173d3dadc49c6b480065c2f9f37">
<ds:Transforms>
<ds:Transform Algorithm="
http://www.w3.org/2000/09/xmldsig#enveloped-signature"/>
<ds:Transform Algorithm="
http://www.w3.org/2001/10/xml-exc-c14n#"/>
</ds:Transforms>
<ds:DigestMethod Algorithm="
http://www.w3.org/2000/09/xmldsig#sha1"/>
<ds:DigestValue>15JIVyYWH37PNoR5V//vnNximDE=</ds:DigestValue>
</ds:Reference>
</ds:SignedInfo>
<ds:SignatureValue>BGvRNYcexkZ/Gg6keywf5zbigUxjTYmw3nVj4XRDBW2YqkPFQcowfw/zL/kOm8LhXLv9bUfg0I/IDTIt+nOAKxi4NEamoMMLRL9EDnG3uxDlFbSJDTWSBXOLOW5b+74tPRE3D9Ztr6kNoOWH2OzW35Em0LtMrgc2khdJN76Mn74mS5ihbJ+oaxkxS3N0rYcvPdaqCle1tV+gV1v7rbp7gan8zGJDqs/BCVOe4qH4S7rzWHdvpXNX+23C2b/uBB0iF5IkJV8GVUF+HD21Fs3qoNySAmbjQMygNiQ3UIIebyRZj5Zrdq+dR8Jcmzxmsnw3jbAPCpSV/EYEp+i6/8l1Eg==</ds:SignatureValue>
<ds:KeyInfo>
<ds:X509Data>
<ds:X509Certificate>MIIDKzCCAhOgAwIBAgIUO+7Y4gRs+UeqFOXN3Chpp/tvxgYwDQYJKoZIhvcNAQEFBQAwGzEZMBcG
A1UEAxMQd3d3LmluYXJjYXNzYS5pdDAeFw0xMTAzMjYxODM0MTlaFw0zMTAzMjYxODM0MTlaMBsx
GTAXBgNVBAMTEHd3dy5pbmFyY2Fzc2EuaXQwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIB
AQCMPVqXaboBV148Vr7fq2nrLYQvH6JJ2R74DLtl0E7VtKl8JxcU4M/+whpVOsdAdrv4DFJyy/Od
XBWWtG4ymbyoMgKMO5tv86l60klW4ZPthOaQf26mybKmtVszp20w1ceAwKCJdS0lr8UThp3n9dL7
095RAsX7wZfczDkex861EaYA9BYkZ4wLByKfZwVya3x8qF1JnNKm8hu1eWcnpTf8qVGK1cNBWxgG
1PP1tbqnqnzBGEDt74t2epfACSmYoopssPM3YxdVLIwZEnKSnlR2gWS2/HqV1lXUSgVwnm5Gd0OX
bDlOYa3/PziXppD547szGh/k1JRBCz+CxBXamUuxAgMBAAGjZzBlMEQGA1UdEQQ9MDuCEHd3dy5p
bmFyY2Fzc2EuaXSGJ2h0dHBzOi8vd3d3LmluYXJjYXNzYS5pdC9pZHAvc2hpYmJvbGV0aDAdBgNV
HQ4EFgQUozkjvieQ70aruNn+iI8okw4SOVowDQYJKoZIhvcNAQEFBQADggEBADa+3qGjas623ssz
SVp2g62cmxBj574reK7tjG4ySGzAb8NTd7xE319F7HDHjQzzAvOLwBqmWWRej3TRu97+l07oWXht
bmyp8xzYuigVfwdb8dtJbCp3IG2Pla7ZovxBBX1PbJwaNzCo279d/Qdcr6mYnIolyBJ2FCXGUFqn
YVQD+lgeYLIh391zBUsIWCQ+/oPKD/oy1heBS01Wt8ejNQeQS1R/EAiC51eZKOzk0NoIbonHQo4f
OvQJVjDjxCszsaHhgfZlKC/hQy1eMDDpvsmnB6wuEF5aNNvYxl8a+qha3lRlqM6sAvaFR6ugX8X+
aymxLQu0yZoEZYXrpcsH6+M=</ds:X509Certificate>
</ds:X509Data>
</ds:KeyInfo>
</ds:Signature>
<saml2:Subject>
<saml2:SubjectConfirmation
Method="urn:oasis:names:tc:SAML:2.0:cm:bearer">
<saml2:SubjectConfirmationData Address="93.70.49.139"
InResponseTo="_37239fdb6e3f76b3008ee0249f7c3518"
NotOnOrAfter="2011-11-28T09:46:20.392Z" Recipient="
https://www.inarcassa.it/Shibboleth.sso/SAML2/POST"/>
</saml2:SubjectConfirmation>
</saml2:Subject>
<saml2:Conditions NotBefore="2011-11-28T09:41:20.392Z"
NotOnOrAfter="2011-11-28T09:46:20.392Z">
<saml2:AudienceRestriction>
<saml2:Audience>https://www.inarcassa.it/shibboleth
</saml2:Audience>
</saml2:AudienceRestriction>
</saml2:Conditions>
<saml2:AuthnStatement AuthnInstant="2011-11-28T09:41:12.568Z">
<saml2:SubjectLocality Address="93.70.49.139"/>
<saml2:AuthnContext>
<saml2:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef>
</saml2:AuthnContext>
</saml2:AuthnStatement>
</saml2:Assertion>
10:41:20.429 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:778]
- Encoding response to SAML request _37239fdb6e3f76b3008ee0249f7c3518 from
relying party https://www.inarcassa.it/shibboleth
10:41:20.431 - INFO [Shibboleth-Audit:970] -
20111128T094120Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|_37239fdb6e3f76b3008ee0249f7c3518|
https://www.inarcassa.it/shibboleth|urn:mace:shibboleth:2.0:profiles:saml2:sso|https://www.inarcassa.it/idp/shibboleth|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_4cee0f36347dd1617d516a89775a489f||||||
2011/11/29 Chad La Joie <lajoie at itumi.biz>
> To go any further you need to post the log of *one* complete request
> showing the issue without removing things you don't think are
> important or adding stuff that you think is.
>
> On Tue, Nov 29, 2011 at 08:11, Daniele Russo <ruda76 at gmail.com> wrote:
> > Have you noticed that the same user tries to login two times in a few
> > seconds?
> > The second request contains the login context that is removed without
> > redirect to login page.
>
>
> --
> Chad La Joie
> www.itumi.biz
> trusted identities, delivered
> --
> To unsubscribe from this list send an email to
> users-unsubscribe at shibboleth.net
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20111129/1c26ade4/attachment-0001.html
More information about the users
mailing list