After sending CheckAuthenticationResponseProvider, no logging of identity verification at provider

[Richard Collette]

 

The tail of my provider log looks like the following, showing that an unsolicited assertion was checked for authenticity by the RP.  We then see a get to the identity endpoint by the RP, to start the process of Identity verification, but nothing happening at the provider is being logged after that point   (transfer to user_xrds.aspx, subsequent call to provider.ashx by the RP, etc.)

 

2012-04-27 15:27:37,218 (GMT-4) [5] INFO  DotNetOpenAuth.Messaging.Channel - Prepared outgoing CheckAuthenticationResponseProvider (2.0) message for <response>:
 is_valid: true
 ns: http://specs.openid.net/auth/2.0

2012-04-27 15:27:37,218 (GMT-4) [5] DEBUG DotNetOpenAuth.Messaging.Channel - Sending message: CheckAuthenticationResponseProvider
2012-04-27 15:27:37,436 (GMT-4) [5] DEBUG OpenIdProviderWebForms.Global - Processing GET on http://localhost:4860/user.aspx/Bob
2012-04-27 15:27:37,436 (GMT-4) [5] DEBUG OpenIdProviderWebForms.Global - User is NOT authenticated.

 

I believe I have logging of everything enabled.

    <root>
      <level value="ALL"/>
      <appender-ref ref="RollingFileAppender"/>
      <appender-ref ref="TracePageAppender"/>
    </root>
    <!-- Specify the level for some specific categories -->
    <logger name="DotNetOpenAuth">
      <level value="ALL"/>
    </logger>

 

The RP log does show that is is performing Identity verification

 

2012-04-27 15:27:37,421 (GMT-4) [5] DEBUG DotNetOpenAuth.OpenId - Verifying assertion matches identifier discovery results...
2012-04-27 15:27:37,436 (GMT-4) [5] DEBUG DotNetOpenAuth.Http - HTTP GET http://localhost:4860/user.aspx/Bob
2012-04-27 15:27:37,701 (GMT-4) [5] DEBUG DotNetOpenAuth.Yadis - An XRDS response was received from GET at user-supplied identifier.
2012-04-27 15:27:37,857 (GMT-4) [5] DEBUG DotNetOpenAuth.Yadis - Total services discovered in XRDS: 2
2012-04-27 15:27:37,857 (GMT-4) [5] DEBUG DotNetOpenAuth.Yadis - [{
 ClaimedIdentifier: http://localhost:4860/user.aspx/Bob
 ProviderLocalIdentifier: http://localhost:4860/user.aspx/Bob
 ProviderEndpoint: http://localhost:4860/Provider.ashx
 OpenID version: 2.0
 Service Type URIs:
  http://specs.openid.net/auth/2.0/signon
  http://openid.net/extensions/sreg/1.1
}, {
 ClaimedIdentifier: http://localhost:4860/user.aspx/Bob
 ProviderLocalIdentifier: http://localhost:4860/user.aspx/Bob
 ProviderEndpoint: http://localhost:4860/Provider.ashx
 OpenID version: 1.0
 Service Type URIs:
  http://openid.net/signon/1.0
  http://openid.net/extensions/sreg/1.1
},]
2012-04-27 15:27:37,873 (GMT-4) [5] DEBUG DotNetOpenAuth.Yadis - Skipping HTML discovery because XRDS contained service endpoints.
2012-04-27 15:27:37,889 (GMT-4) [5] INFO  DotNetOpenAuth.OpenId - Received identity assertion for http://localhost:4860/user.aspx/Bob via http://localhost:4860/Provider.ashx.
2012-04-27 15:27:38,029 (GMT-4) [5] DEBUG OpenIdRelyingPartyWebForms.Global - Processing GET on http://localhost:4856/default.aspx
2012-04-27 15:27:38,294 (GMT-4) [5] DEBUG OpenIdRelyingPartyWebForms.Global - Processing GET on http://localhost:4856/styles.css

[Andrew Arnott]

I assume this is part of your other thread about unsolicited assertions and that your question has been answered.  As John explained, this is by design because the RP can't simply trust an unsolicited assertion for an identifier without checking that the OP Endpoint sending the assertion is authoritative for that identifier.

--
You received this message because you are subscribed to the Google Groups "DotNetOpenAuth" group.
To view this discussion on the web visit https://groups.google.com/d/msg/dotnetopenid/-/xIn2i8pbmvMJ.
To post to this group, send email to dotnet...@googlegroups.com.
To unsubscribe from this group, send email to dotnetopenid...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/dotnetopenid?hl=en.

--
--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre

[Richard Collette]

Hi Andrew..

This is a separate issue actually.  I understand at a high level what it is doing now as I've figured it out through breakpoints, but the logging piece of it does not appear to be working for me on the provider side during verification that the unsolicited assertion claimed identifier matches identifier discovery results.

Thanks,
Rich

To unsubscribe from this group, send email to dotnetopenid+unsubscribe@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/dotnetopenid?hl=en.

[Andrew Arnott]

Hi Richard,

I'm confused at what's not working for you then.  The log looks fine.  What were you expecting to see?

--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre

To view this discussion on the web visit https://groups.google.com/d/msg/dotnetopenid/-/t5khXVHiepIJ.

To post to this group, send email to dotnet...@googlegroups.com.

To unsubscribe from this group, send email to dotnetopenid...@googlegroups.com.

[Richard Collette]

The provider log is just showing

2012-04-27 15:27:37,436 (GMT-4) [5] DEBUG OpenIdProviderWebForms.Global - Processing GET on http://localhost:4860/user.aspx/Bob
2012-04-27 15:27:37,436 (GMT-4) [5] DEBUG OpenIdProviderWebForms.Global - User is NOT authenticated.

Looking at the code for the XrdsPublisher web control.  It does not log the fact that it is doing a Server.Transfer.    So when you look at the OP logs, it just appears as though everything is coming from user.aspx.

Also, once the RP gets the response from user_xrds.aspx, which directs the next call to provider.ashx, the processing that happens in the call to provider.aspx is not in in the OP log.   I would at least expect ProviderEndpoint.Provider.Respond to log something, even if the codebehind of provider.ashx doesn't include any logging statements.

As a new user, its difficult to understand the protocol without these logging statements.  From the logs one gets the impression that only user.aspx is called and there is no notion that user_xrds.aspx or provider.ashx come into play during verification of an unsolicited assertion.

[Andrew Arnott]

Richard,

I believe the logs are complete.  It sounds like you believe that the OP Endpoint (provider.ashx) is hit after the RP performs an HTTP GET on user.aspx and you wonder why that request isn't in the log.  The reason it isn't in the log is because it doesn't happen after -- it happens before.  The RP receives the unsolicited assertion, then verifies by calling the OP Endpoint, then calls user.aspx to verify that the OP endpoint has authority to make the assertion.  The log you sent earlier reveals this flow completely.

To view this discussion on the web visit https://groups.google.com/d/msg/dotnetopenid/-/5f7oqXOBFf8J.

To post to this group, send email to dotnet...@googlegroups.com.

To unsubscribe from this group, send email to dotnetopenid...@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/dotnetopenid?hl=en.

[Richard Collette]

Hmm, what's the emoticon for blushing....

I think I confused a call to user.aspx that is part of the creation of the unsolicited assertion,  with the call from the relying party for verification.   I was only breakpointing the provider and didn't realize there was a call.  I guess the only thing that isn't clear from the logs is the server.transfer calls that occur.

Thanks for your help and sorry of over occupying your time.   Hopefully I can get around to contributing a module to make up for it.

Richard,

To unsubscribe from this group, send email to dotnetopenid+unsubscribe@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/dotnetopenid?hl=en.

[Andrew Arnott]

No problem.  Glad it's all cleared up.

--

You received this message because you are subscribed to the Google Groups "DotNetOpenAuth" group.

To view this discussion on the web visit https://groups.google.com/d/msg/dotnetopenid/-/0R77KgKkJpgJ.

To post to this group, send email to dotnet...@googlegroups.com.

To unsubscribe from this group, send email to dotnetopenid...@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/dotnetopenid?hl=en.