Simpletests for UI of password set and expiry

I think the patch may have failed testing because expiration occurs after the expiration time elapses, not when it elapses. The check for password expiration is this:

if ($account->password_history[0]->created + $expire_int < time()) {

New patch tests this hypothesis by increasing the sleep to two seconds to exceed the expiration time of one second.

All tests pass for the original patch on my local system, but the discrepancy may be due to testbot having executed faster.

testPasswordSet is now consistently failing on testbot. The number of failures varies by run and is either 1 or 4. If I clone the code to my system, though, I can run the tests without failure.

Reverted commit and a subsequent related commit:
http://drupalcode.org/project/password_policy.git/commit/76872c9
http://drupalcode.org/project/password_policy.git/commit/e8b52c3

These failing tests were blocking other automated testing. Need to get testbot working with the tests. It is possible they are catching a bug in recently added code, but I cannot reproduce the failures independently. Need to at least understand why there is a difference in behavior.

Same as #2, updated to apply to latest code. All tests pass on my system, but some should fail on testbot.

After 30 minutes, test is queued and is not running. Maybe I'm being impatient, but I've never known it to take this long. Added a Testbots issue here: #2283213: Queued test not running.

Now it passes on testbot. Will retest and commit if it passes again. Hopefully not some intermittent bug in Password Policy.

10: password_policy-ui-tests-2145649-10.patch queued for re-testing.

Now it fails. Any ideas on how to debug this? Both runs were performed by the same test client.

Patch adds an assertion and removes an ineffectual line of code. I'm wondering if the two consecutive password changes under // Change password twice. might be causing a race condition. I'd think drupalPost() would block, though.

This patch removes nondeterminism from test inputs where the test is failing. Specifically, this eliminates any possibility randomName() would return the same value twice. Doubt it will help.

19: password_policy-ui-tests-2145649-20.patch queued for re-testing.

Will submit an issue to Drupal.org Testbots and see if we can get verbose output, which would probably help debug this. That is my best idea on how to proceed. The behavior varies from run to run with testbot, but always passes on my local system. I've tried most suggestions from here: https://drupal.org/project/testbot

Patch for which I hope we can get verbose output.

Opened Testbots support request: #2283765: Test usually fails on testbot, but always passes locally

24: password_policy-ui-tests-2145649-24.patch queued for re-testing.

24: password_policy-ui-tests-2145649-24.patch queued for re-testing.

Updated to apply on latest code. Also switched to using an unserialized array to define the expire policy, since that is what is being done for other policies now. This patch will still usually fail due to the Testbots problems.

30: password_policy-ui-tests-2145649-30.patch queued for re-testing.

Turns out I am able to reproduce the failures locally, only at a much lower rate. In 1 out of 50 recent runs, the failures occurred. So it does not appear to be a Testbots problem.

Patch adds some sleep(1) calls to check whether failures are a timing issue with the Past Passwords constraint.

3 consecutive passes of #38 and 2 consecutive failures of #30 supports hypothesis of timing problem.

I think this code, which obtains the password history, is the problem:

  $query = db_select('password_policy_history', 'p');
  $query
    ->condition('p.uid', array_keys($accounts)) 
    ->fields('p', array('uid', 'pass', 'created'))
    ->orderBy('created', 'DESC');
    
  foreach ($query->execute() as $record) {
    $accounts[$record->uid]->password_history[] = $record;
  }

The retrieved history is ordered in the array by 'created' time. If there are multiple history entries with the same time, the order will be unspecified. So, for instance, if three passwords are submitted in the same second what is supposedly the most recent password might actually be the third most recent password.

Testbot is probably executing the tests fast enough that the password changes in the test happen in the same second. (Not sure if there is a way to confirm this.)

The password history loading should be changed to order by some sequence number rather than time, so the order is guaranteed to be correct. Will fix the bug separately then again review #30.

Removing #38 as it was just for testing the timing hypothesis.

Unfortunately my fix to ensure correct ordering of the password history did not solve the problem.

Still it seems to be a timing issue because adding the sleep() calls causes the tests to pass.

OK, I will try to reproduce these failures locally so I can more easily debug.

Attempt to hack in some debug output, since I am having difficulty reproducing failures locally.

Password history entries were being added with db_merge() keyed on current time. So if two password changes happen in the same second, they would overwrite.

I believe this will fix the failures.

Went ahead and committed as I think it would be useful to have these tests now. They can be improved with further commits if necessary. Thanks, coltrane.