[CRM-20233] authorize.net IPN fails sometimes due to cache table duplicate key - CiviCRM Issue Tracker

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

Attachments

Activity

People

Assignee:

Unassigned

Reporter:

Jamie McClelland

Votes:

0 Vote for this issue

Watchers:

3 Start watching this issue

Dates

Created:

2017-03-08 19:04

Updated:

2017-10-18 16:19