Answers.Body: <p>To answer my own question:</p>
  <p>Civi::lockManager is expected to be used in a way that will allow one process to acquire a lock (with <code>Civi::lockManager()-&gt;acquire()</code>) such that any other process will be made to wait until the first process has released the lock (either explicitly with <code>Civi::lockManager()-&gt;release()</code>, or simply by completing script execution and ending the mysql connection).</p>
  <p>To demonstrate this, we can run this script in two separate sessions (i.e., two separate cli terminals):</p>
  <pre><code>&lt;?php
  
  $connection_id = CRM_Core_DAO::singleValueQuery('SELECT connection_id()');
  echo &quot;connection id:                  {$connection_id}\n&quot;;
  
  $startTime = time();
  echo &quot;Attempting to acquire lock at:  &quot;. date('c', $startTime) . &quot;\n&quot;;
  $lock = Civi::lockManager()-&gt;acquire('data.contribute.contribution.1', 100);
  
  $lockAcquireTime = time();
  echo &quot;Lock acquired at:               &quot;. date('c', $lockAcquireTime) . &quot;\n&quot;;
  echo &quot;Time elapsed waiting for lock:  &quot;. ($lockAcquireTime - $startTime) . &quot; seconds\n&quot;;
  echo &quot;Lock is acquired:               &quot;. $lock-&gt;isAcquired() . &quot;\n&quot;;
  
  $timeout = 10;
  echo &quot;Sleeping $timeout...\n&quot;;
  sleep($timeout);
  echo &quot;Script ended at:                &quot; . date('c') .&quot;\n&quot;;
  </code></pre>
  <p>Run this script in terminal 1 and observe this output:</p>
  <pre><code>$ cv scr /tmp/locktest.php
  connection id:                  23757
  Attempting to acquire lock at:  2021-11-03T10:41:01-05:00
  Lock acquired at:               2021-11-03T10:41:01-05:00
  Time elapsed waiting for lock:  0 seconds
  Lock is acquired:               1
  Sleeping 10...
  Script ended at:                2021-11-03T10:41:11-05:00
  </code></pre>
  <p>Before that script completes, run it separately in terminal 2, and observe this output:</p>
  <pre><code>$ cv scr /tmp/locktest.php 
  connection id:                  23759
  Attempting to acquire lock at:  2021-11-03T10:41:05-05:00
  Lock acquired at:               2021-11-03T10:41:11-05:00
  Time elapsed waiting for lock:  6 seconds
  Lock is acquired:               1
  Sleeping 10...
  Script ended at:                2021-11-03T10:41:21-05:00
  </code></pre>
  <p>Specifically, compare the output lines labeled &quot;Time elapsed waiting for lock&quot;. In Terminal 1, the lock was acquired instantly. Meanwhile in Terminal 2, execution paused for 6 seconds waiting for <code>Civi::lockManager()-&gt;acquire()</code> to acquire the lock. This demonstrates that lock acquisition will wait (up to the timeout value of 100 seconds, as defined in the second parameter to <code>Civi::lockManager()-&gt;acquire()</code>) until the named lock is free; it then acquires that named lock, which will cause any other processes to pause similarly when they try to acquire a lock of the same name.</p>
  <p>Thanks to @eileen and @Tim Otten for the helpful comments.</p>
  
Answers.ContentLicense: CC BY-SA 4.0
Answers.CreationDate: 2021-11-03T15:44:32.977Z
Answers.LastActivityDate: 2021-11-03T15:44:32.977Z
Answers.UserDisplayName: TwoMice
Answers.Body: <p>The missing piece of info here is when the lock is released</p>
  <pre><code>$lock = Civi::lockManager()-&gt;acquire('data.contribute.contribution.1', 100);
  unset($lock);
  </code></pre>
  <p>instantly releases the lock cos it is part of the classes __destruct</p>
  <p><a href="https://i.sstatic.net/1Fdh6.png" rel="nofollow noreferrer"><img src="https://i.sstatic.net/1Fdh6.png" alt="enter image description here" /></a></p>
  
Answers.ContentLicense: CC BY-SA 4.0
Answers.CreationDate: 2022-08-22T15:49:07.360Z
Answers.Text: Yes, and now a recent commit by @eileen (https://github.com/eileenmcnaughton/nz.co.fuzion.omnipaymultiprocessor/commit/c8b9ab304e5257c19c065358e74883fb59884f79) seems to prevent premature releasing of the lock.
Answers.UserDisplayName: TwoMice
Answers.ContentLicense: CC BY-SA 4.0
Answers.CreationDate: 2022-08-19T22:28:11.023Z
Answers.LastActivityDate: 2022-08-19T22:28:11.023Z
Answers.UserDisplayName: eileen
Body: <p>I'm confused about how Civi::lockManager is supposed to be used in handling sql-level locks on certain processes.</p>
  <p>I'm looking at a few existing code usages (as in <a href="https://github.com/eileenmcnaughton/nz.co.fuzion.omnipaymultiprocessor/blob/249817a1d8eb17be5cd42dd61bc042bca0756f6c/CRM/Core/Payment/OmnipayMultiProcessor.php#L876" rel="nofollow noreferrer">Omnipay here</a> and in <a href="https://github.com/civicrm/civicrm-core/blob/master/api/v3/Job.php#L202" rel="nofollow noreferrer">civicrm core here</a>). These are all using essentially this logic:</p>
  <p><strong>Listing 1:</strong></p>
  <pre><code>  $lock = Civi::lockManager()-&gt;acquire($PROPERLY_FORMATTED_LOCK_NAME);
    if (!$lock-&gt;isAcquired()) {
      // This entity is locked, so don't do anything
    }
    else {
      // This entity is not locked, so go ahead and do that thing.
    }
  </code></pre>
  <p>However, my rather naive testing shows that <code>$lock&gt;isAcquired($ANYTHING)</code> will always return TRUE. Consider this simple test script and its output:</p>
  <p><strong>Listing 2:</strong></p>
  <pre><code>$ cat /tmp/locktest.php
  &lt;?php
  $lockName = 'data.contribute.contribution.1';
  
  $lock = Civi::lockManager()-&gt;acquire($lockName);
  echo(&quot;lock is acquired:&quot; . $lock-&gt;isAcquired()) . &quot;\n&quot;;
  
  $lock = Civi::lockManager()-&gt;acquire($lockName);
  echo(&quot;lock is acquired:&quot; . $lock-&gt;isAcquired()) . &quot;\n&quot;;
  
  $ cv scr /tmp/locktest.php
  lock is acquired:1
  lock is acquired:1
  </code></pre>
  <p>(From my reading, this seems reasonable, considering that mysql <code>GET_LOCK()</code> (which is always called by <code>acquire()</code>) is designed to allow multiple simultaneous locks of the same name. (<a href="https://dev.mysql.com/doc/refman/5.7/en/locking-functions.html#function_get-lock" rel="nofollow noreferrer">Reference mysql docs</a>). I.e., if you ask to acquire a lock of name 'x', mysql will always give it to you. The important step would be using <code>IS_FREE_LOCK()</code> to test whether the lock is actually free.)</p>
  <p>Given the output in Listing 2, how is it possible that the code in Listing 1 is actually testing for the pre-existence of a named lock and avoiding repeat action if that lock is in place?</p>
  
Comments.ContentLicense: CC BY-SA 4.0
Comments.CreationDate: 2021-11-02T19:23:03.317Z
Comments.Text: So listing 2 is not 'real' because you are doing both within the same process / mysql connection
  
  If I open 2 separate mysql sessions & in one put
  ```get_lock('bambi', 100)```
  
  Then I can run that over & over in that session and I will get the lock (result = 1) . In the other session I keep running it and get a result of 0 - because the other session has the lock.
  
  One thing I noticed in the code is that the timeout seems to be only 3 seconds - which might be enough but is less than I expected
  I then run it
Comments.UserDisplayName: eileen
Comments.ContentLicense: CC BY-SA 4.0
Comments.CreationDate: 2021-11-02T20:11:23.217Z
Comments.Text: @eileen OK, I see. You're right: if I put a `sleep()` in there long enough to keep locktest.php running in one terminal, and then run locktest.php in another terminal, that second instance will pause at `Civi::lockManager()->acquire()` until the first process's lock is released. If you'd like, please make an answer, because I think you've answered it. Else I will at some point.
Comments.UserDisplayName: TwoMice
Comments.ContentLicense: CC BY-SA 4.0
Comments.CreationDate: 2021-11-02T20:38:52.250Z
Comments.Text: +1 - you need two separate processes to demonstrate the locking. Re:3 seconds -- it's subjective. For background tasks, I could see a longer wait. For foreground tasks, you have a user waiting for feedback. In either case, a long wait may be a code-smell (*the critical-section is too heavy*).
Comments.UserDisplayName: Tim Otten
Comments.ContentLicense: CC BY-SA 4.0
Comments.CreationDate: 2021-11-09T15:27:02.610Z
Comments.Text: Maybe related? https://github.com/civicrm/civicrm-core/pull/22013
Comments.UserDisplayName: Demerit
Comments.ContentLicense: CC BY-SA 4.0
Comments.CreationDate: 2021-11-09T16:44:44.940Z
Comments.Text: @twomice I've observed on a live site using ACLs heavily that the locks DO get allocated multiple times which causes duplicate DB errors on ACL cache rebuild. That would appear to match scenario 2 above and that's what my PR fixes.
Comments.UserDisplayName: Matthew Wire
Tags: <developer><mysql><core>
Title: How is Civi::lockManager supposed to be used?
ThreadText: # How is Civi::lockManager supposed to be used?
  
  (Asked by: username_0 on 2021-11-02)
  
  I'm confused about how Civi::lockManager is supposed to be used in handling sql-level locks on certain processes.
  
  I'm looking at a few existing code usages (as in [Omnipay here](https://github.com/eileenmcnaughton/nz.co.fuzion.omnipaymultiprocessor/blob/249817a1d8eb17be5cd42dd61bc042bca0756f6c/CRM/Core/Payment/OmnipayMultiProcessor.php#L876) and in [civicrm core here](https://github.com/civicrm/civicrm-core/blob/master/api/v3/Job.php#L202)). These are all using essentially this logic:
  
  **Listing 1:**
  
  ```
    $lock = Civi::lockManager()->acquire($PROPERLY_FORMATTED_LOCK_NAME);
    if (!$lock->isAcquired()) {
      // This entity is locked, so don't do anything
    }
    else {
      // This entity is not locked, so go ahead and do that thing.
    }
  
  ```
  
  However, my rather naive testing shows that `$lock>isAcquired($ANYTHING)` will always return TRUE. Consider this simple test script and its output:
  
  **Listing 2:**
  
  ```
  $ cat /tmp/locktest.php
  <?php
  $lockName = 'data.contribute.contribution.1';
  
  $lock = Civi::lockManager()->acquire($lockName);
  echo("lock is acquired:" . $lock->isAcquired()) . "\n";
  
  $lock = Civi::lockManager()->acquire($lockName);
  echo("lock is acquired:" . $lock->isAcquired()) . "\n";
  
  $ cv scr /tmp/locktest.php
  lock is acquired:1
  lock is acquired:1
  
  ```
  
  (From my reading, this seems reasonable, considering that mysql `GET_LOCK()` (which is always called by `acquire()`) is designed to allow multiple simultaneous locks of the same name. ([Reference mysql docs](https://dev.mysql.com/doc/refman/5.7/en/locking-functions.html#function_get-lock)). I.e., if you ask to acquire a lock of name 'x', mysql will always give it to you. The important step would be using `IS_FREE_LOCK()` to test whether the lock is actually free.)
  
  Given the output in Listing 2, how is it possible that the code in Listing 1 is actually testing for the pre-existence of a named lock and avoiding repeat action if that lock is in place?
  
  **Tags:** developer, mysql, core
  
  > **Comments:**
  > **username_1**: So listing 2 is not 'real' because you are doing both within the same process / mysql connection  If I open 2 separate mysql sessions & in one put ```get_lock('bambi', 100)```  Then I can run that over & over in that session and I will get the lock (result = 1) . In the other session I keep running it and get a result of 0 - because the other session has the lock.  One thing I noticed in the code is that the timeout seems to be only 3 seconds - which might be enough but is less than I expected I then run it  
  > **username_0**: @username_1 OK, I see. You're right: if I put a `sleep()` in there long enough to keep locktest.php running in one terminal, and then run locktest.php in another terminal, that second instance will pause at `Civi::lockManager()->acquire()` until the first process's lock is released. If you'd like, please make an answer, because I think you've answered it. Else I will at some point.  
  > **username_2**: +1 - you need two separate processes to demonstrate the locking. Re:3 seconds -- it's subjective. For background tasks, I could see a longer wait. For foreground tasks, you have a user waiting for feedback. In either case, a long wait may be a code-smell (*the critical-section is too heavy*).  
  > **username_3**: Maybe related? https://github.com/civicrm/civicrm-core/pull/22013  
  > **username_4**: @username_0 I've observed on a live site using ACLs heavily that the locks DO get allocated multiple times which causes duplicate DB errors on ACL cache rebuild. That would appear to match scenario 2 above and that's what my PR fixes.  
  
  ---
  
  ## 2 answers
  
  ### Answer by username_0 on 2021-11-03. Score: 2
  
  To answer my own question:
  
  Civi::lockManager is expected to be used in a way that will allow one process to acquire a lock (with `Civi::lockManager()->acquire()`) such that any other process will be made to wait until the first process has released the lock (either explicitly with `Civi::lockManager()->release()`, or simply by completing script execution and ending the mysql connection).
  
  To demonstrate this, we can run this script in two separate sessions (i.e., two separate cli terminals):
  
  ```
  <?php
  
  $connection_id = CRM_Core_DAO::singleValueQuery('SELECT connection_id()');
  echo "connection id:                  {$connection_id}\n";
  
  $startTime = time();
  echo "Attempting to acquire lock at:  ". date('c', $startTime) . "\n";
  $lock = Civi::lockManager()->acquire('data.contribute.contribution.1', 100);
  
  $lockAcquireTime = time();
  echo "Lock acquired at:               ". date('c', $lockAcquireTime) . "\n";
  echo "Time elapsed waiting for lock:  ". ($lockAcquireTime - $startTime) . " seconds\n";
  echo "Lock is acquired:               ". $lock->isAcquired() . "\n";
  
  $timeout = 10;
  echo "Sleeping $timeout...\n";
  sleep($timeout);
  echo "Script ended at:                " . date('c') ."\n";
  
  ```
  
  Run this script in terminal 1 and observe this output:
  
  ```
  $ cv scr /tmp/locktest.php
  connection id:                  23757
  Attempting to acquire lock at:  2021-11-03T10:41:01-05:00
  Lock acquired at:               2021-11-03T10:41:01-05:00
  Time elapsed waiting for lock:  0 seconds
  Lock is acquired:               1
  Sleeping 10...
  Script ended at:                2021-11-03T10:41:11-05:00
  
  ```
  
  Before that script completes, run it separately in terminal 2, and observe this output:
  
  ```
  $ cv scr /tmp/locktest.php 
  connection id:                  23759
  Attempting to acquire lock at:  2021-11-03T10:41:05-05:00
  Lock acquired at:               2021-11-03T10:41:11-05:00
  Time elapsed waiting for lock:  6 seconds
  Lock is acquired:               1
  Sleeping 10...
  Script ended at:                2021-11-03T10:41:21-05:00
  
  ```
  
  Specifically, compare the output lines labeled "Time elapsed waiting for lock". In Terminal 1, the lock was acquired instantly. Meanwhile in Terminal 2, execution paused for 6 seconds waiting for `Civi::lockManager()->acquire()` to acquire the lock. This demonstrates that lock acquisition will wait (up to the timeout value of 100 seconds, as defined in the second parameter to `Civi::lockManager()->acquire()`) until the named lock is free; it then acquires that named lock, which will cause any other processes to pause similarly when they try to acquire a lock of the same name.
  
  Thanks to @username_1 and @username_2 for the helpful comments.
  
  
  ---
  
  ### Answer by username_1 on 2022-08-19. Score: 1
  
  The missing piece of info here is when the lock is released
  
  ```
  $lock = Civi::lockManager()->acquire('data.contribute.contribution.1', 100);
  unset($lock);
  
  ```
  
  instantly releases the lock cos it is part of the classes \_\_destruct
  
  [![enter image description here](https://i.sstatic.net/1Fdh6.png)](https://i.sstatic.net/1Fdh6.png)
  
  > **Comments:**
  > **username_0**: Yes, and now a recent commit by @username_1 (https://github.com/eileenmcnaughton/nz.co.fuzion.omnipaymultiprocessor/commit/c8b9ab304e5257c19c065358e74883fb59884f79) seems to prevent premature releasing of the lock.  
  
  ---
  
  