Problem : My consumer using OpenID4Java can't associate

[Fwang]

Hello,

I'm making an openid consumer and an openid provider using openid4java
library and I have some problems with the consumer.

When it's a my OP using openid4java, the consumer can associate with
it and verify the server's response. But I have an exception when the
server is for example myopenid.com or openid.aol.com

When the consumer verifies openid.aol.com response, there is an
exception and verification.getStatusMsg() is "Error verifying
signature with the OP: null"

Then I disabled stateless with allowStateless(false) and I got this
exception :
Authentication cannot be performed: no association available and
stateless mode is disabled
org.openid4java.consumer.ConsumerManager.authenticate(ConsumerManager.java:
1022)
org.openid4java.consumer.ConsumerManager.authenticate(ConsumerManager.java:
967)

And there are :
manager.discover(userSuppliedString).toString() => [OpenID1 OP-
endpoint:https://api.screenname.aol.com/auth/openidServer
ClaimedID:http://openid.aol.com/francois08wang Delegate:null]

discovered = manager.associate(discoveries);

discovered.toString() => OpenID1 OP-endpoint:https://
api.screenname.aol.com/auth/openidServer ClaimedID:http://
openid.aol.com/francois08wang Delegate:null
discovered.isVersion2() => false
Association.FAILED_ASSOC_HANDLE.equals(manager.getAssociations().load(discovered.getIdpEndpoint().toString()).getHandle())
=> true

I'm wondering why consumer can't associate with openid.aol.com (or
myopenid.com), maybe I forgot to do something.
Tell me if something is wrong :

User send an openid url to the consumer, then in doPost(...) consumer
calls authRequest(req.getParameter("openid_url"), req, res) that is
the SampleConsumer method.
And in the authRquest method I modified this :
// configure the return_to URL where your application will
receive
// the authentication responses from the OpenID provider
String returnToUrl = "http://192.168.57.154/openid/
consumer";

// --- Forward proxy setup (only if needed) ---

ProxyProperties proxyProps = new ProxyProperties();
proxyProps.setProxyHostName("192.168.57.97");
proxyProps.setProxyPort(3128);
HttpClientFactory.setProxyProperties(proxyProps);

Thanks
François

[Johnny Bufu]

Hi François!

On 15-May-07, at 6:51 AM, Fwang wrote:
> I'm making an openid consumer and an openid provider using openid4java
> library and I have some problems with the consumer.
>
> When it's a my OP using openid4java, the consumer can associate with
> it and verify the server's response. But I have an exception when the
> server is for example myopenid.com or openid.aol.com
>
> When the consumer verifies openid.aol.com response, there is an
> exception and verification.getStatusMsg() is "Error verifying
> signature with the OP: null"

Can you enable debug logging? You can do that in a log4j.properties
file, with a line like this:

log4j.logger.org.openid4java=INFO, <your_log4j_appender>

> Then I disabled stateless with allowStateless(false) and I got this
> exception :
> Authentication cannot be performed: no association available and
> stateless mode is disabled

This is the expected behavior here -- OpenID cannot work with both
verification methods disabled.

> And there are :
> [...]
> Association.FAILED_ASSOC_HANDLE.equals(manager.getAssociations
> ().load(discovered.getIdpEndpoint().toString()).getHandle())
> => true

This only says that the association process failed; it would be
useful to see why exactly it failed.

> I'm wondering why consumer can't associate with openid.aol.com (or
> myopenid.com), maybe I forgot to do something.
> Tell me if something is wrong :
>
> User send an openid url to the consumer, then in doPost(...) consumer
> calls authRequest(req.getParameter("openid_url"), req, res) that is
> the SampleConsumer method.
> And in the authRquest method I modified this :
> // configure the return_to URL where your application will
> receive
> // the authentication responses from the OpenID provider
> String returnToUrl = "http://192.168.57.154/openid/
> consumer";
>
> // --- Forward proxy setup (only if needed) ---
>
> ProxyProperties proxyProps = new ProxyProperties();
> proxyProps.setProxyHostName("192.168.57.97");
> proxyProps.setProxyPort(3128);
> HttpClientFactory.setProxyProperties(proxyProps);

This looks ok - we have basically the same flow and it associates ok
with myopenid.com.

Johnny

[Johnny Bufu]

On 15-May-07, at 10:58 PM, Johnny Bufu wrote:

>> When the consumer verifies openid.aol.com response, there is an
>> exception and verification.getStatusMsg() is "Error verifying
>> signature with the OP: null"
>
> Can you enable debug logging? You can do that in a log4j.properties
> file, with a line like this:
>
> log4j.logger.org.openid4java=INFO, <your_log4j_appender>

That should read DEBUG for full logs, and the log4j.properties should
be in the webapp's classpath (WEB-INF/classes).

Johnny

[Fwang]

I enabled debug logging and this what I get when user send an myopenid
URL:

1) When stateless is disabled

[INFO ] 11:26:05,525 [org.openid4java.discovery.Discovery :
Discovery.java : 181] : Starting discovery on URL identifier:
http://francois.fws.myopenid.com/
[INFO ] 11:26:05,525 [org.openid4java.discovery.Discovery :
Discovery.java : 181] : Starting discovery on URL identifier:
http://francois.fws.myopenid.com/
[INFO ] 11:26:06,898 [org.openid4java.yadis.YadisResolver :
YadisResolver.java : 229] : Yadis discovery succeeded on
http://francois.fws.myopenid.com/
[INFO ] 11:26:06,898 [org.openid4java.yadis.YadisResolver :
YadisResolver.java : 229] : Yadis discovery succeeded on
http://francois.fws.myopenid.com/
[INFO ] 11:26:06,899 [org.openid4java.discovery.Discovery :
Discovery.java : 189] : Using Yadis normalized URL as claimedID:
http://francois.fws.myopenid.com/
[INFO ] 11:26:06,899 [org.openid4java.discovery.Discovery :
Discovery.java : 189] : Using Yadis normalized URL as claimedID:
http://francois.fws.myopenid.com/
[INFO ] 11:26:06,903 [org.openid4java.discovery.Discovery :
Discovery.java : 210] : Discovered 3 OpenID endpoints.
[INFO ] 11:26:06,903 [org.openid4java.discovery.Discovery :
Discovery.java : 210] : Discovered 3 OpenID endpoints.
[INFO ] 11:26:06,904 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 4
[INFO ] 11:26:06,904 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 4

=> So that's ok, Yadis discovery succeeded on http://francois.fws.myopenid.com/
but when ConsumerManager wants to associate :

[ERROR] 11:26:07,166 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 596] : Error talking to http://www.myopenid.com/server
response code: -1
java.net.UnknownHostException: www.myopenid.com
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:177)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at java.net.Socket.connect(Socket.java:469)
at java.net.Socket.<init>(Socket.java:366)
at java.net.Socket.<init>(Socket.java:239)
at
org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:
79)
at
org.apache.commons.httpclient.protocol.ControllerThreadSocketFactory
$1.doit(ControllerThreadSocketFactory.java:90)
at
org.apache.commons.httpclient.protocol.ControllerThreadSocketFactory
$SocketTask.run(ControllerThreadSocketFactory.java:157)
at java.lang.Thread.run(Thread.java:595)

=> There are 4 times this same error, Yadis discovery succeeded before
so why www.myopenid.com is an unknown host ?

[INFO ] 11:26:07,184 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 2
[INFO ] 11:26:07,184 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 2
[INFO ] 11:26:07,186 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.
[INFO ] 11:26:07,186 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.
[INFO ] 11:26:07,187 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 2
[INFO ] 11:26:07,187 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 2
[INFO ] 11:26:07,188 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.
[INFO ] 11:26:07,188 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.
[WARN ] 11:26:07,189 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 648] : Association failed; using first entry:
http://www.myopenid.com/server
[WARN ] 11:26:07,189 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 648] : Association failed; using first entry:
http://www.myopenid.com/server
[INFO ] 11:26:07,200 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 4
[INFO ] 11:26:07,200 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 676] : Trying to associate with http://www.myopenid.com/server
attempts left: 4
[INFO ] 11:26:07,201 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.
[INFO ] 11:26:07,201 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 683] : Found an existing association.

=> So associtation failed, stateless is disabled and I got

"Authentication cannot be performed: no association available and
stateless mode is disabled"

2) When stateless is not disabled

There is the same log in the begining. Association failed but the
Consumer can fall into dumb mode.

[INFO ] 11:43:55,940 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1025] : Creating authentication request for OP-
endpoint: http://www.myopenid.com/server claimedID: http://francois.fws.myopenid.com/
OP-specific ID: http://francois.fws.myopenid.com/
[INFO ] 11:43:55,940 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1025] : Creating authentication request for OP-
endpoint: http://www.myopenid.com/server claimedID: http://francois.fws.myopenid.com/
OP-specific ID: http://francois.fws.myopenid.com/
[INFO ] 11:43:55,943 [org.openid4java.server.RealmVerifier :
RealmVerifier.java : 147] : Realm verified: http://192.168.57.154/openid/consumer
[INFO ] 11:43:55,943 [org.openid4java.server.RealmVerifier :
RealmVerifier.java : 147] : Realm verified: http://192.168.57.154/openid/consumer
[INFO ] 11:43:55,945 [org.openid4java.server.RealmVerifier :
RealmVerifier.java : 147] : Realm verified: http://192.168.57.154/openid/consumer
[INFO ] 11:43:55,945 [org.openid4java.server.RealmVerifier :
RealmVerifier.java : 147] : Realm verified: http://192.168.57.154/openid/consumer
[INFO ] 11:44:23,208 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1087] : Verifying authentication response...
[INFO ] 11:44:23,208 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1087] : Verifying authentication response...
[INFO ] 11:44:23,220 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1111] : Received positive auth response.
[INFO ] 11:44:23,220 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1111] : Received positive auth response.

=> So user is sent to his OP, and says "allow". (Myopenid.com says :
"Please carefully verify whether you wish to trust http://192.168.57.154/openid/consumer
. This trust root is possibly suspect.")

[INFO ] 11:44:23,225 [org.openid4java.discovery.Discovery :
Discovery.java : 181] : Starting discovery on URL identifier:
http://francois.fws.myopenid.com/
[INFO ] 11:44:23,225 [org.openid4java.discovery.Discovery :
Discovery.java : 181] : Starting discovery on URL identifier:
http://francois.fws.myopenid.com/
[INFO ] 11:44:24,080 [org.openid4java.yadis.YadisResolver :
YadisResolver.java : 229] : Yadis discovery succeeded on
http://francois.fws.myopenid.com/
[INFO ] 11:44:24,080 [org.openid4java.yadis.YadisResolver :
YadisResolver.java : 229] : Yadis discovery succeeded on
http://francois.fws.myopenid.com/
[INFO ] 11:44:24,082 [org.openid4java.discovery.Discovery :
Discovery.java : 189] : Using Yadis normalized URL as claimedID:
http://francois.fws.myopenid.com/
[INFO ] 11:44:24,082 [org.openid4java.discovery.Discovery :
Discovery.java : 189] : Using Yadis normalized URL as claimedID:
http://francois.fws.myopenid.com/
[INFO ] 11:44:24,084 [org.openid4java.discovery.Discovery :
Discovery.java : 210] : Discovered 3 OpenID endpoints.
[INFO ] 11:44:24,084 [org.openid4java.discovery.Discovery :
Discovery.java : 210] : Discovered 3 OpenID endpoints.

=> I'm wondering why there is another Yadis discovery ?

[INFO ] 11:44:24,086 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1687] : No association found, contacting the OP
for direct verification...
[INFO ] 11:44:24,086 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1687] : No association found, contacting the OP
for direct verification...

=> association failed before, so Consumer has to send a
check_authentification message to the OP

[ERROR] 11:44:24,107 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 596] : Error talking to http://www.myopenid.com/server
response code: -1
java.net.UnknownHostException: www.myopenid.com
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:177)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at java.net.Socket.connect(Socket.java:469)
at java.net.Socket.<init>(Socket.java:366)
at java.net.Socket.<init>(Socket.java:239)
at
org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:
79)
at
org.apache.commons.httpclient.protocol.ControllerThreadSocketFactory
$1.doit(ControllerThreadSocketFactory.java:90)
at
org.apache.commons.httpclient.protocol.ControllerThreadSocketFactory
$SocketTask.run(ControllerThreadSocketFactory.java:157)
at java.lang.Thread.run(Thread.java:595)

=> There is 2 times this error

[WARN ] 11:44:24,112 [org.openid4java.message.Message : Message.java :
185] : Required parameter missing: ns
[WARN ] 11:44:24,112 [org.openid4java.message.Message : Message.java :
185] : Required parameter missing: ns
[ERROR] 11:44:24,114 [org.openid4java.message.DirectError :
DirectError.java : 75] : Invalid direct error message created:
[ERROR] 11:44:24,114 [org.openid4java.message.DirectError :
DirectError.java : 75] : Invalid direct error message created:
[ERROR] 11:44:24,125 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1737] : Verification failed for: null reason:

Error verifying signature with the OP: null

[ERROR] 11:44:24,125 [org.openid4java.consumer.ConsumerManager :
ConsumerManager.java : 1737] : Verification failed for: null reason:

Error verifying signature with the OP: null

=> And then the "Error verifying signature with the OP: null" I got.

So the problem is OP is an unknown host when the consumer wants to
communicate directly, but why ?

François

[Fwang]

My log4j.properties file wasn't well configured, don't pay attention
if there were two times the same log info in the previous message.

It seems when it's a HTTP POST request (associate,
check_authentification), connection fails. But not when it's a GET
request (openid html document).

François

[Johnny Bufu]

On 16-May-07, at 6:54 AM, Fwang wrote:
> It seems when it's a HTTP POST request (associate,
> check_authentification), connection fails. But not when it's a GET
> request (openid html document).

The logs show network errors when your consumer tries to contact the
OP directly. I would suggest troubleshooting this on the consumer's
host and checking that communication flows ok through the proxy you
have configured.

Johnny

[Marius Scurtescu]

Hi François.

I just realized that you are using a proxy. It is quite possible that
the proxy code in openid4java is broken, not sure if anyone tested it
lately. I asked the original author a few questions and never got a
reply:
http://groups.google.com/group/openid4java/browse_frm/thread/
01f6966600218f02/ae94b04b0e416d72?hl=en#ae94b04b0e416d72

It seems that your proxy does not require authentication, is that
correct?

I can see two possible problems:
1. The code sets proxy credentials in all cases, even if they were
not set (in which cases uses anonymous/anonymous).
2. A call to setDoAuthentication may be required.

Would you be able to make small changes to the openid4java code and
recompile?

Marius

[Fwang]

Actually, the proxy does not require authentication where I work. I
tried to comment line 64 to 69 in HttpClientFactory.java and
recompile. And I still had the same problem.

For setDoAuthentication, I believe if we don't call that method,
DoAuthentification is "false". But as the proxy doesn't require
authentication I don't think it is because of that.

So, I tried at home, I commented the lines after "forward proxy
setup" and ... It worked successfully for myopenid.com :)
Consumer can associate and verify locally the signature and it seems
myopenid.com doesn't support "attribute exchange".
It also worked with "http://www.jkg.in/openid/anything" which is an
anonymous openid provider, and also for openid.aol.com.

There is a weird thing with openid.aol.com : if I said to the
openid4java consumer that my URL is "openid.aol.com/francois08wang/"
then openid.aol.com wants "francois08wang/" to sign in, I can't change
it to "francois08wang" and openid.aol.com finally says that "/" is not
an allowed character.
If there is an issue it is not from openid4java but openid.aol.com :P

Finally, I don't know why it doesn't work where I work, maybe it is
the proxy code in openid4java or it is because of the proxy which
forbids some things.

Thank you,
François

[Marius Scurtescu]

On 18-May-07, at 9:10 AM, Fwang wrote:

>
> Actually, the proxy does not require authentication where I work. I
> tried to comment line 64 to 69 in HttpClientFactory.java and
> recompile. And I still had the same problem.
>
> For setDoAuthentication, I believe if we don't call that method,
> DoAuthentification is "false". But as the proxy doesn't require
> authentication I don't think it is because of that.

If lines 64 to 69 in HttpClientFactory are commented out then
setDoAuthentications is definitely not needed.

I made a small change in revision 256, can you please grab that one
and try again?

In the new version you will have to comment out lines 63 to 68. Not
sure if this will fix your problem, but worth a shot. A safer way to
set the host configuration.

>
> So, I tried at home, I commented the lines after "forward proxy
> setup" and ... It worked successfully for myopenid.com :)

[...]

> Finally, I don't know why it doesn't work where I work, maybe it is
> the proxy code in openid4java or it is because of the proxy which
> forbids some things.

It does look like a proxy issue of some sort, either in the code or
with your specific proxy. I assume that you can use a browser with
that proxy (or other apps)?

Do you have access to the proxy logs, to see if it records any hits
from the openid4java code?

Marius

[Johnny Bufu]

On 18-May-07, at 9:10 AM, Fwang wrote:

> There is a weird thing with openid.aol.com : if I said to the
> openid4java consumer that my URL is "openid.aol.com/francois08wang/"
> then openid.aol.com wants "francois08wang/" to sign in, I can't change
> it to "francois08wang" and openid.aol.com finally says that "/" is not
> an allowed character.
> If there is an issue it is not from openid4java but openid.aol.com :P

[http://]openid.aol.com/francois08wang/ and [http://]openid.aol.com/
francois08wang are two different URLs. You should you only the one
that AOL said is the OpenID URL for you account.

Johnny

[Fwang]

>I made a small change in revision 256, can you please grab that one
>and try again?

Where can I find the revision 256 ?

>I assume that you can use a browser with
>that proxy (or other apps)?

Yes, I can use a browser

>Do you have access to the proxy logs, to see if it records any hits
>from the openid4java code?

No, I don't have acces to the proxy logs

François

[Marius Scurtescu]

On 21-May-07, at 12:24 AM, Fwang wrote:

>> I made a small change in revision 256, can you please grab that one
>> and try again?
> Where can I find the revision 256 ?

In Subversion, you have to checkout the source code and build the
library. I can send you a library built on my machine if you prefer
that, please let me know.

http://code.google.com/p/openid4java/source

Marius