CRM-16387 - CRM_Core_Lock - Fix release of $jobLog. Improve logging.

The code used $jobLog as a hack to avoid acquiring a second lock (without
releasing the first lock).  However, it never detected the release of the
first lock.

diff --git a/CRM/Core/Lock.php b/CRM/Core/Lock.php
index bfa40d0db82eda0e09e86020ad791d8714ea3f5f..fb252d00f2bf68e7e29066dd188841d1c65775bc 100644 (file)
--- a/CRM/Core/Lock.php
+++ b/CRM/Core/Lock.php
@@ -34,6 +34,8 @@
  */
 class CRM_Core_Lock {
 
+  static $jobLog = FALSE;
+
   // lets have a 3 second timeout for now
   const TIMEOUT = 3;
 
@@ -71,12 +73,11 @@ class CRM_Core_Lock {
     if (defined('CIVICRM_LOCK_DEBUG')) {
       CRM_Core_Error::debug_log_message('trying to construct lock for ' . $this->_name);
     }
-    static $jobLog = FALSE;
-    if ($jobLog && CRM_Core_DAO::singleValueQuery("SELECT IS_USED_LOCK( '{$jobLog}')")) {
-      return $this->hackyHandleBrokenCode($jobLog);
+    if (self::$jobLog && CRM_Core_DAO::singleValueQuery("SELECT IS_USED_LOCK( '" . self::$jobLog . "')")) {
+      return $this->hackyHandleBrokenCode(self::$jobLog);
     }
     if (stristr($name, 'civimail.job.')) {
-      $jobLog = $this->_name;
+      self::$jobLog = $this->_name;
     }
     $this->_timeout = $timeout !== NULL ? $timeout : self::TIMEOUT;
 
@@ -91,9 +92,6 @@ class CRM_Core_Lock {
    * @return bool
    */
   public function acquire() {
-    if (defined('CIVICRM_LOCK_DEBUG')) {
-      CRM_Core_Error::debug_log_message('acquire lock for ' . $this->_name);
-    }
     if (!$this->_hasLock) {
       $query = "SELECT GET_LOCK( %1, %2 )";
       $params = array(
@@ -102,8 +100,16 @@ class CRM_Core_Lock {
       );
       $res = CRM_Core_DAO::singleValueQuery($query, $params);
       if ($res) {
+        if (defined('CIVICRM_LOCK_DEBUG')) {
+          CRM_Core_Error::debug_log_message('acquire lock for ' . $this->_name);
+        }
         $this->_hasLock = TRUE;
       }
+      else {
+        if (defined('CIVICRM_LOCK_DEBUG')) {
+          CRM_Core_Error::debug_log_message('failed to acquire lock for ' . $this->_name);
+        }
+      }
     }
     return $this->_hasLock;
   }
@@ -112,9 +118,16 @@ class CRM_Core_Lock {
    * @return null|string
    */
   public function release() {
+    if (defined('CIVICRM_LOCK_DEBUG')) {
+      CRM_Core_Error::debug_log_message('release lock for ' . $this->_name .  ' (' . ($this->_hasLock ? 'hasLock' : '!hasLock') . ')');
+    }
     if ($this->_hasLock) {
       $this->_hasLock = FALSE;
 
+      if (self::$jobLog == $this->_name) {
+        self::$jobLog = FALSE;
+      }
+
       $query = "SELECT RELEASE_LOCK( %1 )";
       $params = array(1 => array($this->_name, 'String'));
       return CRM_Core_DAO::singleValueQuery($query, $params);
@@ -152,7 +165,8 @@ class CRM_Core_Lock {
    */
   public function hackyHandleBrokenCode($jobLog) {
     if (stristr($this->_name, 'job')) {
-      throw new CRM_Core_Exception('lock aquisition for ' . $this->_name . 'attempted when ' . $jobLog . 'is not released');
+      CRM_Core_Error::debug_log_message('lock acquisition for ' . $this->_name . ' attempted when ' . $jobLog . ' is not released');
+      throw new CRM_Core_Exception('lock acquisition for ' . $this->_name . ' attempted when ' . $jobLog . ' is not released');
     }
     if (defined('CIVICRM_LOCK_DEBUG')) {
       CRM_Core_Error::debug_log_message('(CRM-12856) faking lock for ' . $this->_name);