mod_auth_openid fails when an associated server expires its nonces

[foresto]

A few times per week, and sometimes a few times per day, mod_auth_openid fails with the "unspecified" error code and this message in the debug output:

Error in authentication: openid.modauthopenid.nonce: no such field

This seems to occur when mod_auth_openid had established an assocition with the openid provder in the past, but the provider has since expired its old associations & nonces. Considering that such expiration is normal, it seems to me that mod_auth_openid should automatically establish a new association/nonce/whatever in this case, rather than triggering a mysterious authentication failure.

[foresto]

Also of note: This error sometimes goes away when the user tries to authenticate again, but it is sometimes persistent until an admin deletes /tmp/mod_auth_openid.db from the relying party machine.

[bmuller]

For some reason it looks like the code is looking for "openid.modauthopenid.nonce" - when it should be looking for "modauthopenid.nonce". Can you post the relevant section of your apache conf? Also, what version of mod_auth_openid are you using?

Thanks - B

[foresto]

I'm currently using a snapshot from 2010-11-08, and it was doing the same thing with the 0.5 release. I'm using libopkele3 2.0.4. My apache config:

    AuthType OpenID
    require valid-user
    AuthOpenIDCookieLifespan 28800
    AuthOpenIDTrusted ^https://example.com/
    AuthOpenIDLoginPage /dologin/
    AuthOpenIDCookiePath /

[bmuller]

Does it happen with different IdPs or are you just testing with one? I've created a foresto branch - with a possible fix (I've been unable to reproduce the error). If you could try it out and let me know what happens, it would be much appreciated -

Thanks - B

[foresto]

I'm only using it with one provider. It's a production system that is only lightly used for the moment.

I'll try your patch; thanks. It might take a week or two before I know if it works.

[foresto]

Okay, I installed a build with your patch on a test machine, performed one successful authentication, deleted the provider's session store, and restarted the provider. My next attempt to authenticate yielded another "unspecified' error from mod_auth_openid, and this in the debug log:

[Tue Nov 30 12:01:54 2010] [debug] mod_auth_openid.cpp(426): [client 127.0.0.1] *** mod_auth_openid 0.6 module has been called ***, referer: http://localhost:6060/login?openid.assoc_handle=%7BHMAC-SHA256%7D%7B4cf5581c%7D%7BfbZIdQ%3D%3D%7D&openid.claimed_id=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0%2Fidentifier_select&openid.identity=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0%2Fidentifier_select&openid.mode=checkid_setup&openid.ns=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0&openid.realm=http%3A%2F%2Flocalhost%2Ftestdir%2F&openid.return_to=http%3A%2F%2Flocalhost%2Ftestdir%2F%3F%26modauthopenid.nonce%3DePGjPcvjNO&openid.trust_root=http%3A%2F%2Flocalhost%2Ftestdir%2F
[Tue Nov 30 12:01:54 2010] [error] [client 127.0.0.1] Error in authentication: openid.openid.assoc_handle: no such field, referer: http://localhost:6060/login?openid.assoc_handle=%7BHMAC-SHA256%7D%7B4cf5581c%7D%7BfbZIdQ%3D%3D%7D&openid.claimed_id=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0%2Fidentifier_select&openid.identity=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0%2Fidentifier_select&openid.mode=checkid_setup&openid.ns=http%3A%2F%2Fspecs.openid.net%2Fauth%2F2.0&openid.realm=http%3A%2F%2Flocalhost%2Ftestdir%2F&openid.return_to=http%3A%2F%2Flocalhost%2Ftestdir%2F%3F%26modauthopenid.nonce%3DePGjPcvjNO&openid.trust_root=http%3A%2F%2Flocalhost%2Ftestdir%2F

Deleting /tmp/mod_auth_openid.db and restarting apache got authentication to work again.

[foresto]

The patch is now on a production system, and I just saw the "unspecified" error with the openid.openid.assoc_handle: no such field message again. This time it happened in a real user's session, without me forcing the identity provider to flush its associations.

[bmuller]

Do you know what IdP software the provider is using?

[foresto]

Yes, the provider is using the janrain python openid library, as distributed with Ubuntu linux.

[oskapt]

I'm experiencing this issue now, with openid 0.6 going against Atlassian CrowdID server. Removing the openid.db doesn't solve the issue, and it happens 100% of the time.

[oskapt]

Specifically, I'm getting:

Error in authentication: openid.modauthopenid.nonce: no such field

It works if I attempt to authenticate against Gmail, but not against Atlassian. I'll try the foresto branch if it's still available.

[oskapt]

And, like foresto, the error has now changed to:

Error in authentication: openid.openid.assoc_handle: no such field

[oskapt]

This error looked like the previous one, where openid. was prepended to something that already had the openid. prefix. I expanded on the previous code change in types.h and have the following:

--- types.h.orig        2010-12-11 11:31:07.000000000 -0500
+++ types.h     2012-03-09 20:38:31.000000000 -0500
@@ -47,12 +47,24 @@
     modauthopenid_message_t(params_t& _bom) { bom = _bom; };
     bool has_field(const string& n) const { 
       string prefix = "modauthopenid.";
-      string param = (n.compare(0, prefix.size(), prefix)==0) ? n : "openid."+n;
+      string prefix2 = "openid.";
+      string param;
+      if( n.compare(0, prefix.size(), prefix)==0 || n.compare(0, prefix2.size(), prefix2)==0) { 
+        param = n;
+      } else {
+        param = "openid."+n;
+      }
       return  bom.has_param(param); 
     };
     const string& get_field(const string& n) const { 
       string prefix = "modauthopenid.";
-      string param = (n.compare(0, prefix.size(), prefix)==0) ? n : "openid."+n;
+      string prefix2 = "openid.";
+      string param;
+      if( n.compare(0, prefix.size(), prefix)==0 || n.compare(0, prefix2.size(), prefix2)==0) { 
+        param = n;
+      } else {
+        param = "openid."+n;
+      }
       return bom.get_param(param); 
     };
     bool has_ns(const string& uri) const { return bom.has_ns(uri); };

Please forgive the fact that I'm not a C programmer by trade - I'm not 100% sure that this is doing what I want it to do. It does stop the "no such field" errors, but it does not give me the ability to log into Atlassian CrowdID. I'm also still able to log in via other endpoints, so I'm inclined to believe that the diff provided solves the double-prepending issue.

It would be nice if recompiling the module with -DDEBUG gave me more than this for information:

Error in authentication: failed to check_authentication()

Not terribly helpful.

[docwhat]

I'm running across this in certain situations. In my case, it's visiting: http://shortname/ instead of http://shortname.example.com

Here's my apache conf:

<Proxy /railsapp>
    Order deny,allow
    Allow from all
</Proxy>

<Proxy http://127.0.0.1:2012>

  Order deny,allow
  Allow from all

  AuthType OpenID
  AuthOpenIDTrusted https://openid.example.com
  AuthOpenIDDistrusted localhost
  AuthOpenIDTrustRoot http://shortname.example.com
  AuthOpenIDSingleIdP https://openid.example.com
  require valid-user

</Proxy>

RewriteCond %{REQUEST_URI} !^/railsapp/assets/
RewriteRule ^/railsapp/?.*$ http://127.0.0.1:2012%{REQUEST_URI} [P,QSA,L]

Alias /railsapp /u/railsapp/current/public
<Directory /u/railsapp/current/public>
  Order deny,allow
  Allow from all

  Header unset Last-Modified
  Header unset ETag
  FileETag None

  ExpiresActive On
  ExpiresDefault "access plus 1 year"

</Directory>

Looking as @oskapt's C code, it seems to be doing this:

If n starts with "modauthopenid." or "openid." then param is set to n. Otherwise, param is set n with "openid." prepended.

I'm unfamiliar with the string construct so I'm assuming n.compare(...) == 0 means that they are equal, like cmp.

Does that sound right?

[bmuller]

OK - I've create a new branch to incorporate these changes named prefixfix. This should fix the issue of double openid prefixes.

[docwhat]

Okay. The prefixfix branch is not breaking anything. However, I'm not sure how I got into the state where I got the Error in authentication: openid.modauthopenid.nonce: no such field errors in the first place.

I'll leave it running on our production system for a bit more and see if it the original error re-occurs or not.

Ciao!

[ramayer]

Same error that was originally described ("This seems to occur when mod_auth_openid had established an assocition with the openid provder in the past, but the provider has since expired its old associations & nonces. Considering that such expiration is normal, it seems to me that mod_auth_openid should automatically establish a new association/nonce/whatever in this case, rather than triggering a mysterious authentication failure.") is occurring with whatever version is distributed with Ubuntu 14.04 LTS .

A crontab to delete /tmp/mod_auth_openid.db every hour is a workaround that kinda works; but is annoying if someone tries to log in at that moment.

EDIT: A slightly less drastic workaround that seems to be working here --- a crontab that does:

sqlite3 /tmp/mod_auth_openid.db "delete from associations where ( (julianday('now') - 2440587.5) * 86400.0  - expires_on + 14 * 60 * 60 * 24) > 60;"

that runs every few minutes. Would love to see a better fix, though.