Shibboleth session and variables problems

Andrea Di Mario andrea.dimario at speakage.com
Tue Dec 13 08:11:41 GMT 2011 

Hi, thanks for you reply, here shibd.log:
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (2)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:KeyDescriptor
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling
attributes for DOM element (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: ds:KeyInfo
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling
attributes for DOM element (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : found namespace
declaration, adding it to the list of namespaces on the XMLObject
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: ds:X509Data
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (ds:X509Data)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (ds:X509Data)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (ds:X509Data)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: ds:X509Certificate
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (ds:X509Certificate)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (ds:X509Certificate)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (ds:X509Certificate)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (1)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (1)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (1)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (3)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:SingleLogoutService
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:SingleLogoutService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:SingleLogoutService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling
attributes for DOM element (md:SingleLogoutService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:SingleLogoutService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : element had no children
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (4)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:NameIDFormat
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:NameIDFormat)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:NameIDFormat)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:NameIDFormat)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (5)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:SingleSignOnService
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:SingleSignOnService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:SingleSignOnService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling
attributes for DOM element (md:SingleSignOnService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:SingleSignOnService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : element had no children
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (6)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (1)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:ContactPerson
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:ContactPerson)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:ContactPerson)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling
attributes for DOM element (md:ContactPerson)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing generic attribute
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:ContactPerson)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:SurName
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:SurName)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:SurName)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:SurName)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (1)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject.Builder : located
XMLObjectBuilder for element name: md:EmailAddress
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
element (md:EmailAddress)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling DOM
element (md:EmailAddress)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : unmarshalling child
nodes of DOM element (md:EmailAddress)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (0)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (2)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : processing text
content at position (2)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:IDPSSODescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:Extensions)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (shibmd:Scope)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:X509Data)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:X509Certificate)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:KeyDescriptor)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:KeyInfo)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:X509Data)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (ds:X509Certificate)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:SingleLogoutService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:NameIDFormat)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:SingleSignOnService)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:ContactPerson)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for children with propagation set to true
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:SurName)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:EmailAddress)
2011-12-13 08:06:37 DEBUG XMLTooling.XMLObject : releasing cached DOM
representation for (md:EntityDescriptor)
2011-12-13 08:06:37 INFO Shibboleth.Application : building TrustEngine
of type Chaining...
2011-12-13 08:06:37 INFO XMLTooling.TrustEngine.Chaining : building
TrustEngine of type ExplicitKey
2011-12-13 08:06:37 INFO XMLTooling.TrustEngine.Chaining : building
TrustEngine of type PKIX
2011-12-13 08:06:37 INFO Shibboleth.Application : building
AttributeExtractor of type XML...
2011-12-13 08:06:37 DEBUG Shibboleth.AttributeExtractor : using local
resource (/etc/shibboleth/attribute-map.xml), will monitor for changes
2011-12-13 08:06:37 DEBUG Shibboleth.AttributeExtractor : loading
configuration from external resource...
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : loaded XML
resource (/etc/shibboleth/attribute-map.xml)
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : creating
mapping for Attribute urn:oid:2.5.4.49
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : creating
mapping for Attribute uid
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : creating
mapping for Attribute disableFlgIULM
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : creating
mapping for Attribute codiceFiscaleIULM
2011-12-13 08:06:37 INFO Shibboleth.AttributeExtractor : creating
mapping for Attribute corsoStudiIULM
2011-12-13 08:06:37 INFO Shibboleth.Application : building
AttributeFilter of type XML...
2011-12-13 08:06:37 DEBUG Shibboleth.AttributeFilter : using local
resource (/etc/shibboleth/attribute-policy.xml), will monitor for
changes
2011-12-13 08:06:37 DEBUG Shibboleth.AttributeFilter : loading
configuration from external resource...
2011-12-13 08:06:37 INFO Shibboleth.AttributeFilter : loaded XML
resource (/etc/shibboleth/attribute-policy.xml)
2011-12-13 08:06:37 INFO Shibboleth.Application : building
AttributeResolver of type Query...
2011-12-13 08:06:37 INFO Shibboleth.Application : building
CredentialResolver of type File...
2011-12-13 08:06:37 DEBUG XMLTooling.CredentialResolver.File : key
encoding format for (/etc/shibboleth/sp2SSkey.pem) dynamically
resolved as (PEM)
2011-12-13 08:06:37 INFO XMLTooling.CredentialResolver.File : loading
private key from file (/etc/shibboleth/sp2SSkey.pem)
2011-12-13 08:06:37 DEBUG XMLTooling.CredentialResolver.File :
certificate encoding format for (/etc/shibboleth/sp2SScert.pem)
dynamically resolved as (PEM)
2011-12-13 08:06:37 INFO XMLTooling.CredentialResolver.File : loading
certificate from file (/etc/shibboleth/sp2SScert.pem)
2011-12-13 08:06:37 INFO Shibboleth.Listener : registered remoted
message endpoint (default::getHeaders::Application)
2011-12-13 08:06:37 INFO Shibboleth.Listener : listener service starting
2011-12-13 08:06:37 INFO XMLTooling.StorageService : cleanup thread
started...running every 900 seconds
2011-12-13 08:07:01 DEBUG Shibboleth.Listener [1]: dispatching message
(default::getHeaders::Application)
2011-12-13 08:07:01 DEBUG Shibboleth.Listener [1]: dispatching message
(default/Login::run::SAML2SI)
2011-12-13 08:07:01 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
validating input
2011-12-13 08:07:01 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
marshalling, deflating, base64-encoding the message
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: starting to
marshal samlp:AuthnRequest
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: creating root
element to marshall
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling
namespace attributes for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling text
and child elements for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: starting to
marshalling saml:Issuer
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: creating root
element to marshall
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling
namespace attributes for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling text
and child elements for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: starting to
marshalling samlp:NameIDPolicy
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: creating root
element to marshall
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling
namespace attributes for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: marshalling text
and child elements for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: caching DOM for XMLObject
2011-12-13 08:07:01 DEBUG XMLTooling.XMLObject [1]: caching DOM for
XMLObject (document is bound)
2011-12-13 08:07:01 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
marshalled message:
<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
AssertionConsumerServiceIndex="1"
Destination="https://idp.iulm.it/simplesaml/saml2/idp/SSOService.php"
ID="_f191842b40f5ec038e648f09d0ce17b9"
IssueInstant="2011-12-13T08:07:01Z" Version="2.0"><saml:Issuer
xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">https://videogalleryiulm.dev.speakagefarm.info/shibboleth</saml:Issuer><samlp:NameIDPolicy
AllowCreate="1"/></samlp:AuthnRequest>
2011-12-13 08:07:01 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
signing the message
2011-12-13 08:07:01 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
message encoded, sending redirect to client

And transaction.log (the last transaction that works):
2011-11-21 19:29:49 INFO Shibboleth-TRANSACTION [4]: Cached the
following attributes with session (ID:
_36eaef9b563285286d17183e879c1cd3) for (applicationId: default) {
2011-11-21 19:29:49 INFO Shibboleth-TRANSACTION [4]: }
2011-11-21 19:29:50 INFO Shibboleth-TRANSACTION [4]: New session (ID:
_3478400d9eec6f7cfe94a3039a5148ce) with (applicationId: default) for
principal from (IdP:
https://idp.iulm.it/simplesaml/saml2/idp/metadata.php) at
(ClientAddress: 131.175.1.21) with (NameIdentifier:
_9817d985cf94e61f75feccdc97423781f1f4dc57aa) using (Protocol:
urn:oasis:names:tc:SAML:2.0:protocol)
2011-11-21 19:29:50 INFO Shibboleth-TRANSACTION [4]: Cached the
following attributes with session (ID:
_3478400d9eec6f7cfe94a3039a5148ce) for (applicationId: default) {
2011-11-21 19:29:50 INFO Shibboleth-TRANSACTION [4]: }
2011-11-21 19:30:51 INFO Shibboleth-TRANSACTION [4]: New session (ID:
_b095828332f130225c6205f658cc37ac) with (applicationId: default) for
principal from (IdP:
https://idp.iulm.it/simplesaml/saml2/idp/metadata.php) at
(ClientAddress: 131.175.1.21) with (NameIdentifier:
_9e88f7753e6f864baebb3f001fa654e61de04d783f) using (Protocol:
urn:oasis:names:tc:SAML:2.0:protocol)
2011-11-21 19:30:51 INFO Shibboleth-TRANSACTION [4]: Cached the
following attributes with session (ID:
_b095828332f130225c6205f658cc37ac) for (applicationId: default) {
2011-11-21 19:30:51 INFO Shibboleth-TRANSACTION [4]: }
2011-11-21 19:31:29 INFO Shibboleth-TRANSACTION [2]: Destroyed session
(applicationId: default) (ID: _b095828332f130225c6205f658cc37ac)
2011-11-21 20:05:03 INFO Shibboleth-TRANSACTION [4]: New session (ID:
_68dbcc91ee8ce77d37482253c1841cb2) with (applicationId: default) for
principal from (IdP:
https://idp.iulm.it/simplesaml/saml2/idp/metadata.php) at
(ClientAddress: 131.175.1.21) with (NameIdentifier:
_9af37a1bdfb41ca747728db1e62dafcd10f47f12f4) using (Protocol:
urn:oasis:names:tc:SAML:2.0:protocol)
2011-11-21 20:05:03 INFO Shibboleth-TRANSACTION [4]: Cached the
following attributes with session (ID:
_68dbcc91ee8ce77d37482253c1841cb2) for (applicationId: default) {
2011-11-21 20:05:03 INFO Shibboleth-TRANSACTION [4]: }
2011-11-21 20:07:01 INFO Shibboleth-TRANSACTION [2]: Destroyed session
(applicationId: default) (ID: _68dbcc91ee8ce77d37482253c1841cb2)

Best regards.


2011/12/12 Cantor, Scott <cantor.2 at osu.edu>:
> On 12/12/11 4:12 AM, "Andrea Di Mario" <andrea.dimario at speakage.com> wrote:
>
>>Hi all, i'm a new Shibboleth user. I configured a Shibboleth SP
>>without problems and it create sessions with IdP. Now, it don't create
>>any sessions in transaction.log and i can't take shibboleth variable
>>from apache variables' $_SERVER.
>
> If the SP were running, you would have logs available indicating what it's
> doing and why it's no longer working. There could be issues with the IdP
> releasing attributes depending on the flows involved and your certificate
> perhaps expiring or changing, or a metadata problem. There's nothing here
> to go on.
>
> -- Scott
>
> --
> To unsubscribe from this list send an email to users-unsubscribe at shibboleth.net



-- 
Andrea Di Mario
SPEAKAGE

More information about the users mailing list