When running lock.test locally, I've been noticing the "Lock extended by this request" assertion fails some of the time, without any apparent reason. The assertions are as follows:

...
$this->assertTrue(lock_acquire('system_test_lock_acquire'), t('Lock acquired by this request.'), t('Lock'));
$this->assertTrue(lock_acquire('system_test_lock_acquire'), t('Lock extended by this request.'), t('Lock'));
...

So two calls to lock_acquire() right next to each other. Then in the update query:


    $success = (bool) db_update('semaphore')
      ->fields(array('expire' => $expire))
      ->condition('name', $name)
      ->condition('value', _lock_id())
      ->execute();
    if (!$success) {
      // The lock was broken.
      unset($locks[$name]);
    }

Sometimes $success is FALSE if the old $expire is exactly the same as the new one, because no rows are affected by the query. This only happens if the lock_acquire()'s run fast enough (in the same millisecond) but it still seems like a bug worth fixing.

CommentFileSizeAuthor
#8 838976-8-lock-db_update-bug.patch1.61 KBcarlos8f
#4 838976_lock-acquire_2.patch718 bytesekes
#2 838976-2-lock-db_update-bug.patch1.54 KBcarlos8f
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

carlos8f’s picture

carlos8f CreditAttribution: carlos8f commented

It probably doesn't help that I'm on a 32-bit system (apple macbook) which has trouble handling seconds + milliseconds as a float. microtime(TRUE) returns precision of only 1/100 second, instead of 1/1000 as on a 64-bit machine. With these decimated microtime values, it appears that "internally" PHP still knows there is more precision there (== comparison fails), but "externally" (when the float is cast to a string, or put into a db query) the precision is lost. Here's a perplexing test:

$times = array(microtime(TRUE), microtime(TRUE));
var_dump($times);
if ($times[1] > $times[0]) print "$times[1] is greater than $times[0]\n";
if ($times[1] != $times[0]) print "$times[1] is not equal to $times[0]\n";

Output:

array(2) {
  [0]=>
  float(1277681494.07)
  [1]=>
  float(1277681494.07)
}
1277681494.07 is greater than 1277681494.07
1277681494.07 is not equal to 1277681494.07

As you can see, precision is decimated when outputting as a string, but not when comparing these variables in an expression. Yick!

carlos8f’s picture

carlos8f CreditAttribution: carlos8f commented
Status: Active » Needs review
FileSize
838976-2-lock-db_update-bug.patch1.54 KB

Before patch lock.test failed 4/5 times on my machine, with patch I get all passes.

ekes’s picture

ekes CreditAttribution: ekes commented

+1 for the issue.

I've experienced this on a box running D6 when the work done is sometimes trivial between lock_acquire()'s (i.e. takes less than 0.0044. sec). I can't make it fail the _tests_ for D7 because running in simpletest is slower, but can replicate the issue outside the tests.

+1 I think for the solution.

Just a question. Adding 0.01 which is the 32-bit accuracy isn't going to cause any weird problem on a 64-bit system where it could (just could) update with a smaller value a fraction later?
My only other solution(s) were to add a select query after returning 'false' from the update and before returning saying the lock was broken; or mysql style get the rows affected not necessarily changed (but that's out of the database layer so I'm guessing not cross-platform enough).

ekes’s picture

ekes CreditAttribution: ekes commented
FileSize
838976_lock-acquire_2.patch718 bytes

Just the alternative way I ended up using, it's a small extra query. I'm not sure which is preferable.

Anonymous’s picture

Anonymous (not verified) CreditAttribution: Anonymous commented

subscribe.

Anonymous’s picture

Anonymous (not verified) CreditAttribution: Anonymous commented

i think we should proceed with #2. still looking, but i think its the cleaner approach.

Anonymous’s picture

Anonymous (not verified) CreditAttribution: Anonymous commented
Status: Needs review » Needs work

first issue, this looks broken:

       unset($locks[$name]);
     }
+    // Record the lock's new expiration.
+    $locks[$name] = $expire;
+

don't we want to only do that if $success == true?

carlos8f’s picture

carlos8f CreditAttribution: carlos8f commented
Status: Needs work » Needs review
FileSize
838976-8-lock-db_update-bug.patch1.61 KB

Yes, that was broken. Rerolled to fix that.

Anonymous’s picture

Anonymous (not verified) CreditAttribution: Anonymous commented

ok, that looks all good to me. this may be a kitten-killing suggestion, but this is a test that could use the testing profile. i'm ok if you want to leave that out, but i certainly added it when i was looking at it because it takes literally half the time to run...

will RTBC it if the bot comes back green.

Anonymous’s picture

Anonymous (not verified) CreditAttribution: Anonymous commented

oh, and looking at the test, the API really needs a lock_renew(). the code is twice as hard to read without that, but i guess that's for D8.

xjm’s picture

xjm
she/her
Primary language English
CreditAttribution: xjm commented

Regarding microtime(), see also: