Problem

  • "401 Invalid authentication" errors caused by a too large time offset/deviation of the local server time from universal time.
  • There can be multiple causes for authentication errors, but a local time offset should be determinable and exposed as a unique/own error.

Goal

  • Shortcut debugging in case of 401 authentication errors due to local server time offset.

Details

  • We can improve the client-side implementation to automatically detect a too high time offset/deviation from universal time by parsing/evaluating the date in the HTTP response headers and comparing it to the local server time.
  • If the offset gets too large, the module should log a more severe error message that precisely states the time offset problem.
  • Ideally, this error handling should happen within the generic Mollom PHP class, so all client implementations can benefit from it (and not only Drupal).

Related issues

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

couturier’s picture

This might be of interest, my hosts just upgraded a patch to the server for my site so that the time is now automatically synced to eliminate the frequent invalidation of Mollom API keys that has been happening since my upgrade to Mollom 7.x-2.0. They told me they have multiple Drupal sites on that server but that mine was the only one with a Mollom API key invalidation problem. Up until now, my hosts had watched the server time and tried not to let it stray more than one minute either way, but apparently they had not been monitoring it closely enough to keep the Mollom API keys validated.

Significantly, my site was the only Drupal 7 site on that server. The others had no problems running Mollom in Drupal 6, even with a time offset. So, I'm wondering if is possible with Mollom for D7 to make it not quite so sensitive to the time offset, for the benefit of people who do not have access to auto syncing of server time? Or, is there some other difference between the way Mollom for D6 works versus D7? To repeat, in our instance, we had the same server with multiple sites running Mollom, and the D7 site failed frequently while the D6 sites did not. Also, it seems odd to me that I ran Mollom in D7 on this same server from November 2011 to mid-spring 2012 with zero problems. It was not until immediately upon my upgrade to 7.x-2.0 that the frequent invalidation began. Just thought this might be of interest. Thanks for all your help, sun.

sun’s picture

Category: task » feature

@couturier: One major difference between 1.x and 2.x of the Mollom module is the communication protocol it uses. 1.x used XML-RPC, while 2.x uses two-legged OAuth. OAuth v1 is a precisely defined W3C/industry standard protocol that is not only used by Mollom, but also by Google, Twitter, Facebook, and other web services and platforms. The OAuth protocol requires to create a signature for every HTTP request, which among other parameters also involves the current server time, in order to prevent malicious replay attacks. The OAuth protocol allows for a minor deviation of the server time, but the offset must not be too large. Thus, if the client's server time is not synchronized with world clocks, then it is not able to perform valid OAuth requests against any OAuth provider, which includes all aforementioned sites and services. (That said, it's possible that some of them do not validate the timestamp, but in that case, they do not adhere to the OAuth standard.)

couturier’s picture

Okay, now I understand. Thank you. I wonder if we should add information on the Mollom module page to alert new users that the server they use must be synced precisely? This might help avoid confusion in advance. My hosts are large providers of Drupal hosting with thousands of sites, and some of their servers are automatically synced and some aren't, so even the big hosts might not always be up on how important that is for Mollom beginning with 7.x-2.x.

sun’s picture

Status: Active » Needs work
FileSize
1.98 KB

Attached patch implements the HTTP response header parsing within the Mollom PHP class, and throws an appropriate/specialized exception when the time offset is too large.

The effective code looks very simple, but wasn't super-simple to figure out ;)

Remaining todos:

- Figure out where to display

- Tests (by mocking/faking the mollom_test_server time); with special attention to: The new exception should be caught wherever the former authentication exception is caught.

sun’s picture

Category: feature » task
Status: Needs work » Needs review
FileSize
19.2 KB
29.8 KB
7.53 KB

Alright:

Attached patch implements a full client time validation and outputs an appropriate error message in case the OAuth validation fails due to a too large time offset from UTC.

To manually test this, I changed my local system time to be ~30 minutes in the past.

Screenies:

mollom-time-offset-admin.png

mollom-time-offset-status-report.png

sun’s picture

Issue tags: +Needs manual testing
FileSize
11.29 KB

Hm. I spent a some hours with writing and debugging tests for this.

However, I ultimately had to find out that PHP is not able to override the Date HTTP header in the response. The SAPI/web server (e.g., Apache) always sets that response header, and there is no way to override it from PHP.

I tested with PHP's native header(), debugged the state in apache_response_headers() and headers_list(), and also tried whether overriding $_SERVER['REQUEST_TIME'] and other superglobals makes any difference [all of this in a simple debug.php script outside of Drupal], to no avail.

Attached patch contains the test code for posterity. The new test will fail, because the mocked server time offset does not work.

However, it looks like we cannot test this in an automated way.

Status: Needs review » Needs work

The last submitted patch, mollom.time-offset.6.patch, failed testing.

sun’s picture

Status: Needs work » Needs review
FileSize
8.55 KB

In turn, here's the same patch as #6, but without automated test coverage.

Is anyone able and willing to manually test this to confirm my test results? :)

Test plan:

  1. Apply this patch to a git checkout or latest 7.x-2.x-dev, on your local machine.
  2. Change your system time to be in the past; more than 10 minutes in the past.
  3. Verify that the Mollom settings page shows a corresponding error message, and that it also appears on the Status report.
  4. Verify that the error disappears directly after correcting your system time.

That would be highly appreciated.

couturier’s picture

Wish I could help, but I don't have system access. If you wanted to contact my host directly for help testing, it is Kurt Vanderwater and his staff, kvanderw, also on IRC #drupal-oklahoma. He might remember encountering this issue with my site and others back in June.

sun’s picture

Version: 7.x-2.x-dev » 6.x-2.x-dev
Status: Needs review » Patch (to be ported)

Hm, yeah, testing this is not particularly easy. So, to simplify testing: Committed to 7.x-2.x.

A new development snapshot will be available within the next 12 hours. This improvement will be available in the next official release.

Marking for backport.

couturier’s picture

Update: This was a server time offset problem. My host just fixed it from being 7 minutes off. No specific error message was showing up with dev installed, so maybe this patch isn't working?

Review:

  • My site had a server-time offset invalidation in June 2012.
  • My host fixed this on the server.
  • Everything worked fine until January 15, 2013.
  • So, I installed Mollom 7.x-2.3+9-dev to see if I would get an error message about a server time problem (even though my host was supposed to have fixed this).
  • All I see is the following:
TYPE	 mollom
DATE	 Tuesday, January 15, 2013 - 12:37
USER admin
LOCATION	 http://fashionbelle.com/admin/reports/status
REFERRER	 http://fashionbelle.com/admin/reports
MESSAGE	 Invalid API keys.
Error 401: Invalid authentication.

Request: POST http://rest.mollom.com/v1/site/31f7e1a1b384843df2e340f88ada861f
  platformName = 'Drupal'
  platformVersion = '7.18'
  clientName = 'Mollom'
  clientVersion = '7.x-2.3+9-dev'
Request headers:
  Accept = 'application/xml, application/json;q=0.8, */*;q=0.5'
  Content-Type = 'application/x-www-form-urlencoded'
  Authorization = 'OAuth oauth_consumer_key="31f7e1a1b384843df2e340f88ada861f", oauth_version="1.0", oauth_nonce="88ec9f6b37691c8dadf18ba4671ed0eb", oauth_timestamp="1358275051", oauth_signature_method="HMAC-SHA1", oauth_signature="cKzf2VI%2BcCq2E2VIpPnpyhkDD0E%3D"'
Invalid API keys.

SEVERITY	error

There is no message about server time. So, is it a server time offset problem and the patch didn't work?

Strangely, I also noticed that even though I have Mollom set to block all form submissions if Mollom is down, I am still getting tons of spam comments getting through my forms, dozens every minute. This has never happened before.

sun’s picture

@couturier: Sorry, you're right, the maximum allowed server time offset in the committed code was not correct. The maximum is 5 minutes.

I've committed and pushed a fix for 7.x-2.x now.

This change this needs to be backported to 6.x-2.x.

sun’s picture

Status: Patch (to be ported) » Needs review
FileSize
13.16 KB

Status: Needs review » Needs work

The last submitted patch, 0001-1649326-by-sun-Added-error-handling-in-case-the-loca.patch, failed testing.

sun’s picture

Status: Needs work » Needs review
FileSize
13.15 KB
sun’s picture

Status: Needs review » Fixed

Committed and pushed to 6.x-2.x.

Automatically closed -- issue fixed for 2 weeks with no activity.

  • Commit a6a3e84 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1649326 by sun: Added error handling in case the local server time is...
  • Commit ada74b8 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1649326 by sun: Added error handling in case the local server time is...

  • Commit a6a3e84 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1649326 by sun: Added error handling in case the local server time is...
  • Commit ada74b8 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1649326 by sun: Added error handling in case the local server time is...