Details
-
Type:
Bug
-
Status: Open
-
Priority:
Trivial
-
Resolution: Unresolved
-
Affects Version/s: 4.7.16
-
Fix Version/s: None
-
Component/s: Core CiviCRM
-
Labels:None
-
Versioning Impact:Patch (backwards-compatible bug fixes)
-
Documentation Required?:None
-
Funding Source:Needs Funding
-
Verified?:No
Description
There appears to be a race condition when setting a cache item.
Our nginx log show three IPNs from authorize.net at the same time.
The ConfigAndLog shows several SQL failures to insert a record into the civicrm_cache table (coming from CRM_Core_BAO_CustomField::getFields()) due to a key violation due to a record with the same date, group and path already existing.
I suspect that the first IPN starts to insert the record into the cache table. Before it finishes, the second and third IPN search for the cache record and don't find it. Then, the first IPN completes the insertion. And then the second and third IPN fail to insert their records.
Is there any kind of transaction or locking mechanism we can put in place to delay the search for a cache record if another cache record is in the process of being inserted?
Here is our log from nginx:
/var/log/nginx/onenorthside.access.log.2.gz:198.241.168.60 - - [27/Feb/2017:04:18:15 -0500] "POST /sites/all/modules/civicrm/extern/authorizeIPN.php HTTP/1.1" 500 5 "-" "-" /var/log/nginx/onenorthside.access.log.2.gz:198.241.168.60 - - [27/Feb/2017:04:18:15 -0500] "POST /sites/all/modules/civicrm/extern/authorizeIPN.php HTTP/1.1" 500 5 "-" "-" /var/log/nginx/onenorthside.access.log.2.gz:198.241.168.60 - - [27/Feb/2017:04:18:16 -0500] "POST /sites/all/modules/civicrm/extern/authorizeIPN.php HTTP/1.1" 200 5 "-" "-"
It shows three IPNs from authorize.net at exactly the same second. Two of them failed (with 500 error codes) and one succeeded.
Here are the corresponding lines in ConfigAndLog
Feb 27 04:18:15 [info] Contribution record updated successfully Feb 27 04:18:15 [info] $Fatal Error Details = Array ( [callback] => Array ( [0] => CRM_Core_Error [1] => exceptionHandler ) [code] => -5 [message] => DB Error: already exists [mode] => 16 [debug_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [type] => DB_Error [user_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [to_string] => [db_error: message="DB Error: already exists" code=-5 mode=callback callback=CRM_Core_Error::exceptionHandler prefix="" info="INSERT INTO civicrm_cache (`component_id`,`crea ted_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date']"] ) Feb 27 04:18:15 [info] $backTrace = #0 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Error.php(932): CRM_Core_Error::backtrace("backTrace", TRUE) #1 [internal function](): CRM_Core_Error::exceptionHandler(Object(DB_Error)) #2 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(921): call_user_func((Array:2), Object(DB_Error)) #3 /var/www/powerbase/sites/all/modules/civicrm/packages/DB.php(985): PEAR_Error->__construct("DB Error: already exists", -5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created _date`,`data`,`group_name`,...") #4 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(575): DB_Error->__construct(-5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,. ..") #5 [internal function](): PEAR->_raiseError(Object(DB_mysqli), NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #6 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(224): call_user_func_array((Array:2), (Array:8)) #7 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->__call("raiseError", (Array:7)) #8 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #9 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(933): DB_common->raiseError(-5, NULL, NULL, NULL, "1062 ** Duplicate entry 'contact fields-custom importableFields bfdc225400586...") [message] => DB Error: already exists [message] => DB Error: already exists [mode] => 16 [debug_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [type] => DB_Error [user_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [to_string] => [db_error: message="DB Error: already exists" code=-5 mode=callback callback=CRM_Core_Error::exceptionHandler prefix="" info="INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date']"] ) Feb 27 04:18:15 [info] $backTrace = #0 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Error.php(932): CRM_Core_Error::backtrace("backTrace", TRUE) #1 [internal function](): CRM_Core_Error::exceptionHandler(Object(DB_Error)) #2 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(921): call_user_func((Array:2), Object(DB_Error)) #3 /var/www/powerbase/sites/all/modules/civicrm/packages/DB.php(985): PEAR_Error->__construct("DB Error: already exists", -5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #4 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(575): DB_Error->__construct(-5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #5 [internal function](): PEAR->_raiseError(Object(DB_mysqli), NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #6 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(224): call_user_func_array((Array:2), (Array:8)) #7 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->__call("raiseError", (Array:7)) #8 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #9 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(933): DB_common->raiseError(-5, NULL, NULL, NULL, "1062 ** Duplicate entry 'contact fields-custom importableFields bfdc225400586...") #10 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(403): DB_mysqli->mysqliRaiseError() #11 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1216): DB_mysqli->simpleQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #12 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(2438): DB_common->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #13 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(1627): DB_DataObject->_query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #14 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(354): DB_DataObject->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #15 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(1297): CRM_Core_DAO->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", FALSE) #16 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/Cache.php(173): CRM_Core_DAO::executeQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", (Array:0), TRUE, NULL, FALSE, FALSE) #17 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/CustomField.php(640): CRM_Core_BAO_Cache::setItem((Array:0), "contact fields", "custom importableFields bfdc2254005862e4c470d47832cbc1fd") #18 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1953): CRM_Core_BAO_CustomField::getFields("ContributionRecur", FALSE, FALSE, NULL, NULL, FALSE, FALSE, FALSE) #19 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1924): _civicrm_api_get_custom_fields("ContributionRecur", (Array:3)) #20 /var/www/powerbase/sites/all/modules/civicrm/api/v3/Generic.php(107): _civicrm_api_get_fields("ContributionRecur", TRUE, (Array:3)) #21 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_generic_getfields((Array:9)) #22 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(161): Civi\API\Provider\MagicFunctionProvider->invoke((Array:9)) #23 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #24 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getfields", (Array:2)) #25 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(83): civicrm_api3("ContributionRecur", "getfields", (Array:1)) #26 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Subscriber/APIv3SchemaAdapter.php(62): _civicrm_api3_api_getfields((Array:9)) #27 [internal function](): Civi\API\Subscriber\APIv3SchemaAdapter->onApiPrepare(Object(Civi\API\Event\PrepareEvent), "api.prepare", Object(Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher)) #28 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/EventDispatcher.php(164): call_user_func((Array:2), Object(Civi\API\Event\PrepareEvent), "api.prepare", Object(Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher)) #29 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/EventDispatcher.php(53): Symfony\Component\EventDispatcher\EventDispatcher->doDispatch((Array:5), "api.prepare", Object(Civi\API\Event\PrepareEvent)) #30 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/ContainerAwareEventDispatcher.php(170): Symfony\Component\EventDispatcher\EventDispatcher->dispatch("api.prepare", Object(Civi\API\Event\PrepareEvent)) #31 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(248): Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher->dispatch("api.prepare", Object(Civi\API\Event\PrepareEvent)) #32 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(160): Civi\API\Kernel->prepare(Object(Civi\API\Provider\MagicFunctionProvider), (Array:9)) #33 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #34 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getsingle", (Array:2)) #35 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(2124): civicrm_api3("ContributionRecur", "getsingle", (Array:1)) #36 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(4497): CRM_Contribute_BAO_Contribution::repeatTransaction(Object(CRM_Contribute_BAO_Contribution), (Array:19), (Array:7), "13") #37 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/BaseIPN.php(453): CRM_Contribute_BAO_Contribution::completeOrder((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur), Object(CRM_Contribute_BAO_Contribution), TRUE, FALSE) #38 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(212): CRM_Core_Payment_BaseIPN->completeTransaction((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur)) #39 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(96): CRM_Core_Payment_AuthorizeNetIPN->recur((Array:19), (Array:9), (Array:7), FALSE) #40 /var/www/powerbase/sites/all/modules/civicrm/extern/authorizeIPN.php(46): CRM_Core_Payment_AuthorizeNetIPN->main() #41 {main} Feb 27 04:18:15 [info] $Fatal Error Details = Array ( [callback] => Array ( [0] => CRM_Core_Error [1] => exceptionHandler ) [code] => -5 [message] => DB Error: already exists [mode] => 16 [debug_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [type] => DB_Error [user_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [to_string] => [db_error: message="DB Error: already exists" code=-5 mode=callback callback=CRM_Core_Error::exceptionHandler prefix="" info="INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date']"] ) Feb 27 04:18:15 [info] $backTrace = #0 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Error.php(932): CRM_Core_Error::backtrace("backTrace", TRUE) #1 [internal function](): CRM_Core_Error::exceptionHandler(Object(DB_Error)) #2 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(921): call_user_func((Array:2), Object(DB_Error)) #3 /var/www/powerbase/sites/all/modules/civicrm/packages/DB.php(985): PEAR_Error->__construct("DB Error: already exists", -5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #4 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(575): DB_Error->__construct(-5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #5 [internal function](): PEAR->_raiseError(Object(DB_mysqli), NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #6 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(224): call_user_func_array((Array:2), (Array:8)) #7 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->__call("raiseError", (Array:7)) #8 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #9 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(933): DB_common->raiseError(-5, NULL, NULL, NULL, "1062 ** Duplicate entry 'contact fields-custom importableFields bfdc225400586...") #10 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(403): DB_mysqli->mysqliRaiseError() #11 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1216): DB_mysqli->simpleQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #12 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(2438): DB_common->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #13 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(1627): DB_DataObject->_query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #14 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(354): DB_DataObject->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #15 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(1297): CRM_Core_DAO->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", FALSE) #16 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/Cache.php(173): CRM_Core_DAO::executeQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", (Array:0), TRUE, NULL, FALSE, FALSE) #17 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/CustomField.php(640): CRM_Core_BAO_Cache::setItem((Array:0), "contact fields", "custom importableFields bfdc2254005862e4c470d47832cbc1fd") #18 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1953): CRM_Core_BAO_CustomField::getFields("ContributionRecur", FALSE, FALSE, NULL, NULL, FALSE, FALSE, FALSE) #19 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1924): _civicrm_api_get_custom_fields("ContributionRecur", (Array:3)) #20 /var/www/powerbase/sites/all/modules/civicrm/api/v3/Generic.php(107): _civicrm_api_get_fields("ContributionRecur", TRUE, (Array:3)) #21 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_generic_getfields((Array:9)) #22 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(161): Civi\API\Provider\MagicFunctionProvider->invoke((Array:9)) #23 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #24 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getfields", (Array:2)) #25 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(83): civicrm_api3("ContributionRecur", "getfields", (Array:1)) #26 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Subscriber/APIv3SchemaAdapter.php(62): _civicrm_api3_api_getfields((Array:9)) #27 [internal function](): Civi\API\Subscriber\APIv3SchemaAdapter->onApiPrepare(Object(Civi\API\Event\PrepareEvent), "api.prepare", Object(Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher)) #28 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/EventDispatcher.php(164): call_user_func((Array:2), Object(Civi\API\Event\PrepareEvent), "api.prepare", Object(Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher)) #29 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/EventDispatcher.php(53): Symfony\Component\EventDispatcher\EventDispatcher->doDispatch((Array:5), "api.prepare", Object(Civi\API\Event\PrepareEvent)) #30 /var/www/powerbase/sites/all/modules/civicrm/vendor/symfony/event-dispatcher/Symfony/Component/EventDispatcher/ContainerAwareEventDispatcher.php(170): Symfony\Component\EventDispatcher\EventDispatcher->dispatch("api.prepare", Object(Civi\API\Event\PrepareEvent)) #31 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(248): Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher->dispatch("api.prepare", Object(Civi\API\Event\PrepareEvent)) #32 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(160): Civi\API\Kernel->prepare(Object(Civi\API\Provider\MagicFunctionProvider), (Array:9)) #33 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #34 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getsingle", (Array:2)) #35 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(2124): civicrm_api3("ContributionRecur", "getsingle", (Array:1)) #36 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(4497): CRM_Contribute_BAO_Contribution::repeatTransaction(Object(CRM_Contribute_BAO_Contribution), (Array:19), (Array:7), "13") #37 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/BaseIPN.php(453): CRM_Contribute_BAO_Contribution::completeOrder((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur), Object(CRM_Contribute_BAO_Contribution), TRUE, FALSE) #38 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(212): CRM_Core_Payment_BaseIPN->completeTransaction((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur)) #39 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(96): CRM_Core_Payment_AuthorizeNetIPN->recur((Array:19), (Array:9), (Array:7), FALSE) #40 /var/www/powerbase/sites/all/modules/civicrm/extern/authorizeIPN.php(46): CRM_Core_Payment_AuthorizeNetIPN->main() #41 {main} Feb 27 04:18:15 [info] $Fatal Error Details = Array ( [callback] => Array ( [0] => CRM_Core_Error [1] => exceptionHandler ) [code] => -5 [message] => DB Error: already exists [mode] => 16 [debug_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [type] => DB_Error [user_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [to_string] => [db_error: message="DB Error: already exists" code=-5 mode=callback callback=CRM_Core_Error::exceptionHandler prefix="" info="INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date']"] ) Feb 27 04:18:15 [info] $backTrace = #0 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Error.php(932): CRM_Core_Error::backtrace("backTrace", TRUE) #1 [internal function](): CRM_Core_Error::exceptionHandler(Object(DB_Error)) #2 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(921): call_user_func((Array:2), Object(DB_Error)) #3 /var/www/powerbase/sites/all/modules/civicrm/packages/DB.php(985): PEAR_Error->__construct("DB Error: already exists", -5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #4 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(575): DB_Error->__construct(-5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #5 [internal function](): PEAR->_raiseError(Object(DB_mysqli), NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #6 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(224): call_user_func_array((Array:2), (Array:8)) #7 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->__call("raiseError", (Array:7)) #8 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #9 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(933): DB_common->raiseError(-5, NULL, NULL, NULL, "1062 ** Duplicate entry 'contact fields-custom importableFields bfdc225400586...") #10 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(403): DB_mysqli->mysqliRaiseError() #11 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1216): DB_mysqli->simpleQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #12 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(2438): DB_common->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #13 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(1627): DB_DataObject->_query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #14 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(354): DB_DataObject->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #15 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(1297): CRM_Core_DAO->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", FALSE) #16 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/Cache.php(173): CRM_Core_DAO::executeQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", (Array:0), TRUE, NULL, FALSE, FALSE) #17 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/CustomField.php(640): CRM_Core_BAO_Cache::setItem((Array:0), "contact fields", "custom importableFields bfdc2254005862e4c470d47832cbc1fd") #18 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1953): CRM_Core_BAO_CustomField::getFields("ContributionRecur", FALSE, FALSE, NULL, NULL, FALSE, FALSE, FALSE) #19 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1924): _civicrm_api_get_custom_fields("ContributionRecur", (Array:3)) #20 /var/www/powerbase/sites/all/modules/civicrm/api/v3/Generic.php(107): _civicrm_api_get_fields("ContributionRecur", TRUE, (Array:3)) #21 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_generic_getfields((Array:9)) #22 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(161): Civi\API\Provider\MagicFunctionProvider->invoke((Array:9)) #23 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #24 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getfields", (Array:2)) #25 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(83): civicrm_api3("ContributionRecur", "getfields", (Array:1)) #26 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(394): _civicrm_api3_api_getfields((Array:7)) #27 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(320): Civi\API\Kernel->createError("DB Error: already exists", (Array:0), (Array:7), 0) #28 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(105): Civi\API\Kernel->formatException(Object(CiviCRM_API3_Exception), (Array:7)) #29 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getsingle", (Array:2)) #30 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(2124): civicrm_api3("ContributionRecur", "getsingle", (Array:1)) #31 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(4497): CRM_Contribute_BAO_Contribution::repeatTransaction(Object(CRM_Contribute_BAO_Contribution), (Array:19), (Array:7), "13") #32 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/BaseIPN.php(453): CRM_Contribute_BAO_Contribution::completeOrder((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur), Object(CRM_Contribute_BAO_Contribution), TRUE, FALSE) #33 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(212): CRM_Core_Payment_BaseIPN->completeTransaction((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur)) #34 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(96): CRM_Core_Payment_AuthorizeNetIPN->recur((Array:19), (Array:9), (Array:7), FALSE) #35 /var/www/powerbase/sites/all/modules/civicrm/extern/authorizeIPN.php(46): CRM_Core_Payment_AuthorizeNetIPN->main() #36 {main} Feb 27 04:18:15 [info] $Fatal Error Details = Array ( [callback] => Array ( [0] => CRM_Core_Error [1] => exceptionHandler ) [code] => -5 [message] => DB Error: already exists [mode] => 16 [debug_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [type] => DB_Error [user_info] => INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date'] [to_string] => [db_error: message="DB Error: already exists" code=-5 mode=callback callback=CRM_Core_Error::exceptionHandler prefix="" info="INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,`path`) VALUES (NULL,"2017-02-27 04:18:15","a:0:{}","contact fields","custom importableFields bfdc2254005862e4c470d47832cbc1fd") [nativecode=1062 ** Duplicate entry 'contact fields-custom importableFields bfdc2254005862e4c470d4783' for key 'UI_group_path_date']"] ) Feb 27 04:18:15 [info] $backTrace = #0 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Error.php(932): CRM_Core_Error::backtrace("backTrace", TRUE) #1 [internal function](): CRM_Core_Error::exceptionHandler(Object(DB_Error)) #2 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(921): call_user_func((Array:2), Object(DB_Error)) #3 /var/www/powerbase/sites/all/modules/civicrm/packages/DB.php(985): PEAR_Error->__construct("DB Error: already exists", -5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #4 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(575): DB_Error->__construct(-5, 16, (Array:2), "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #5 [internal function](): PEAR->_raiseError(Object(DB_mysqli), NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #6 /var/www/powerbase/sites/all/modules/civicrm/packages/PEAR.php(224): call_user_func_array((Array:2), (Array:8)) #7 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->__call("raiseError", (Array:7)) #8 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -5, NULL, NULL, "INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", "DB_Error", TRUE) #9 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(933): DB_common->raiseError(-5, NULL, NULL, NULL, "1062 ** Duplicate entry 'contact fields-custom importableFields bfdc225400586...") #10 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/mysqli.php(403): DB_mysqli->mysqliRaiseError() #11 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/common.php(1216): DB_mysqli->simpleQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #12 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(2438): DB_common->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #13 /var/www/powerbase/sites/all/modules/civicrm/packages/DB/DataObject.php(1627): DB_DataObject->_query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #14 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(354): DB_DataObject->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...") #15 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/DAO.php(1297): CRM_Core_DAO->query("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", FALSE) #16 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/Cache.php(173): CRM_Core_DAO::executeQuery("INSERT INTO civicrm_cache (`component_id`,`created_date`,`data`,`group_name`,...", (Array:0), TRUE, NULL, FALSE, FALSE) #17 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/BAO/CustomField.php(640): CRM_Core_BAO_Cache::setItem((Array:0), "contact fields", "custom importableFields bfdc2254005862e4c470d47832cbc1fd") #18 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1953): CRM_Core_BAO_CustomField::getFields("ContributionRecur", FALSE, FALSE, NULL, NULL, FALSE, FALSE, FALSE) #19 /var/www/powerbase/sites/all/modules/civicrm/api/v3/utils.php(1924): _civicrm_api_get_custom_fields("ContributionRecur", (Array:3)) #20 /var/www/powerbase/sites/all/modules/civicrm/api/v3/Generic.php(107): _civicrm_api_get_fields("ContributionRecur", TRUE, (Array:3)) #21 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_generic_getfields((Array:9)) #22 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(161): Civi\API\Provider\MagicFunctionProvider->invoke((Array:9)) #23 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(92): Civi\API\Kernel->runRequest((Array:7)) #24 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getfields", (Array:2)) #25 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(83): civicrm_api3("ContributionRecur", "getfields", (Array:1)) #26 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(394): _civicrm_api3_api_getfields((Array:7)) #27 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(320): Civi\API\Kernel->createError("DB Error: already exists", (Array:0), (Array:7), 0) #28 /var/www/powerbase/sites/all/modules/civicrm/Civi/API/Kernel.php(105): Civi\API\Kernel->formatException(Object(CiviCRM_API3_Exception), (Array:7)) #29 /var/www/powerbase/sites/all/modules/civicrm/api/api.php(43): Civi\API\Kernel->runSafe("ContributionRecur", "getsingle", (Array:2)) #30 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(2124): civicrm_api3("ContributionRecur", "getsingle", (Array:1)) #31 /var/www/powerbase/sites/all/modules/civicrm/CRM/Contribute/BAO/Contribution.php(4497): CRM_Contribute_BAO_Contribution::repeatTransaction(Object(CRM_Contribute_BAO_Contribution), (Array:19), (Array:7), "13") #32 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/BaseIPN.php(453): CRM_Contribute_BAO_Contribution::completeOrder((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur), Object(CRM_Contribute_BAO_Contribution), TRUE, FALSE) #33 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(212): CRM_Core_Payment_BaseIPN->completeTransaction((Array:19), (Array:9), (Array:7), Object(CRM_Core_Transaction), Object(CRM_Contribute_BAO_ContributionRecur)) #34 /var/www/powerbase/sites/all/modules/civicrm/CRM/Core/Payment/AuthorizeNetIPN.php(96): CRM_Core_Payment_AuthorizeNetIPN->recur((Array:19), (Array:9), (Array:7), FALSE) #35 /var/www/powerbase/sites/all/modules/civicrm/extern/authorizeIPN.php(46): CRM_Core_Payment_AuthorizeNetIPN->main() #36 {main} Feb 27 04:18:15 [info] Receipt sent Feb 27 04:18:15 [info] Success: Database updated