2

Environment:

  • CiviCRM 5.5.x is the version that created the ones that are now trying to update, but we are now on the latest version 5.11.00 Drupal 7.x

  • Webform CiviCRM 7.x-4.20+16-dev

Issue:

The first payment made via Webform CiviCRM with 4 1-year terms (Annual) is correctly made in CiviCRM with the payment profile created successfully in Paypal Website Payment Pro. One year after the original transaction, an IPN appears to be sent back from Paypal WPP (copied below) but there is no change on the CiviCRM Recurring Contribution to show the transaction.

Suggestions? Can someone triage this as a Webform CiviCRM issue, CiviCRM bug, or Paypal WPP issue?

At first, I thought the IPN wasn't sending, so I ran the Civi upgrade to 5.11.00 and had Paypal resend the IPN. I checked the CiviCRM System Log table and found the IPN there. The contribution record, however, shows no update.

IPN log:

"{"amount":"100.00","initial_payment_amount":"0.00","profile_status":"Active","payer_id":"E42LJNE93RWRS","product_type":"1","ipn_track_id":"ea7354b7cadf0","outstanding_balance":"0.00","shipping":"0.00","charset":"windows-1252","period_type":" Regular","payment_gross":"100.00","currency_code":"USD","receipt_id":"1095-1202-0757-8493","verify_sign":"ARTWVaUGckuviK6HZ-Of6l88vDtdApgb5SsBR5toeMzYD61j13z0iSqX","payment_cycle":"Yearly","txn_type":"recurring_payment","receiver_id":"XBC22BNDGX5QA","payment_fee":"3.00","mc_currency":"USD","transaction_subject":"Webform Payment: 100 Per 1 year","protection_eligibility":"Ineligible","payer_status":"unverified","first_name":"First","product_name":"Webform Payment: : 100 Per 1 year","amount_per_cycle":"100.00","mc_gross":"100.00","payment_date":"04:11:20 Mar 04, 2019 PST","rp_invoice_id":"i=287cdb784fe4fcdd731906c53e048cdc&m=contribute&c=4729&r=178&b=&p=","payment_status":"Completed","business":"ouremail@ourdomain","last_name":"Last","txn_id":"6EH773960F7425301","mc_fee":"3.00","time_created":"16:30:53 Mar 04, 2018 PST","resend":"true","payment_type":"instant","notify_version":"3.8","recurring_payment_id":"I-1PBATXDD4H0C","payer_email":"[email protected]","receiver_email":"[email protected]","next_payment_date":"02:00:00 Mar 04, 2020 PST","tax":"0.00","residence_country":"US"}"

My rationale for posting it here is I'm not sure where the issue lies so I am happy to report/test anything needed to clear it up.

The Recurring series in CiviCRM the above IPN should update

Update 3/19/2019 - on the latest version of Civi and Webform CiviCRM I created a new recurring profile of $1.00/day and it successfully processed in Paypal each time. CiviCRM only has a record of the first transaction and is receiving the IPN's for the followups but is not doing anything with them. Here are some IPN below (edited for privacy)

The cancellation from Paypal did not cancel anything in Civi:

{"payment_cycle":"Daily","txn_type":"recurring_payment_profile_cancel","last_name":"last","next_payment_date":"N/A","residence_country":"US","initial_payment_amount":"0.00","rp_invoice_id":"i=c83d98a31d0e2c2a5cf3173493e24e3b&m=contribute&c=16014&r=830&b=&p=","currency_code":"USD","time_created":"14:16:08 Mar 14, 2019 PDT","verify_sign":"AyT1wi4GzlURUfQbTmQWfTBcmyeoAgAjHAleKj2b1QyzJd-.4gNAHVEt","period_type":" Regular","payer_status":"unverified","tax":"0.00","payer_email":"[email protected]","first_name":"first","receiver_email":"[email protected]","payer_id":"S5E6YRTVCSZTQ","product_type":"1","shipping":"0.00","amount_per_cycle":"1.00","profile_status":"Cancelled","charset":"windows-1252","notify_version":"3.9","amount":"1.00","outstanding_balance":"0.00","recurring_payment_id":"I-F4WEDCKXYUFS","product_name":"Webform Payment","ipn_track_id":"c7efd7f383b01"}

One of the Payment notices did not create a Contribution in Civi:

{"mc_gross":"1.00","period_type":" Regular","outstanding_balance":"0.00","next_payment_date":"03:00:00 Mar 19, 2019 PDT","protection_eligibility":"Ineligible","payment_cycle":"Daily","tax":"0.00","payer_id":"S5E6YRTVCSZTQ","payment_date":"05:09:39 Mar 18, 2019 PDT","payment_status":"Completed","product_name":"Webform Payment: Membership Forms Debugging Page: 1 Per 1 day","charset":"windows-1252","rp_invoice_id":"i=c83d98a31d0e2c2a5cf3173493e24e3b&m=contribute&c=16014&r=830&b=&p=","recurring_payment_id":"I-F4WEDCKXYUFS","first_name":"first","mc_fee":"0.33","notify_version":"3.9","amount_per_cycle":"1.00","payer_status":"unverified","currency_code":"USD","business":"[email protected]","verify_sign":"AFgGSSN7T0eV820ZsLG2eXpvjHjxA2u3dUQBLcGbSQLiJfOaSXghKIV-","payer_email":"[email protected]","initial_payment_amount":"0.00","profile_status":"Active","amount":"1.00","txn_id":"5489090059341273U","payment_type":"instant","last_name":"last","receiver_email":"[email protected]","payment_fee":"0.33","receiver_id":"XBC22BNDGX5QA","txn_type":"recurring_payment","mc_currency":"USD","residence_country":"US","receipt_id":"5598-9968-4788-6393","transaction_subject":"Webform Payment","payment_gross":"1.00","shipping":"0.00","product_type":"1","time_created":"14:16:08 Mar 14, 2019 PDT","ipn_track_id":"195d7793815d3"}

Edit 2: I've installed https://github.com/eileenmcnaughton/nz.co.fuzion.notificationlog and retried an IPN that failed with a backtrace. Any thoughts? 

drush cvapi NotificationLog.retry system_log_id=12638 debug=1
PayPalFailure: Missing Parameter b                                                                                                                          [error]
Array
(
    [trace] => #0 /myserver/public_html/sites/all/modules/civicrm/CRM/Core/Payment/PayPalProIPN.php(436): CRM_Core_Payment_PayPalProIPN->getValue('b', true)
#1 /myserver/public_html/sites/all/modules/civicrm_extensions/nz.co.fuzion.notificationlog-master/api/v3/NotificationLog/Retry.php(75): CRM_Core_Payment_PayPalProIPN->main()
#2 /myserver/public_html/sites/all/modules/civicrm_extensions/nz.co.fuzion.notificationlog-master/api/v3/NotificationLog/Retry.php(24): _civicrm_api3_notification_log_process(Array)
#3 /myserver/public_html/sites/all/modules/civicrm/Civi/API/Provider/MagicFunctionProvider.php(100): civicrm_api3_notification_log_retry(Array)
#4 /myserver/public_html/sites/all/modules/civicrm/Civi/API/Kernel.php(169): Civi\API\Provider\MagicFunctionProvider->invoke(Array)
#5 /myserver/public_html/sites/all/modules/civicrm/Civi/API/Kernel.php(100): Civi\API\Kernel->runRequest(Array)
#6 /myserver/public_html/sites/all/modules/civicrm/api/api.php(23): Civi\API\Kernel->runSafe('NotificationLog', 'retry', Array, NULL)
#7 /myserver/public_html/sites/all/modules/civicrm/drupal/drush/civicrm.drush.inc(1558): civicrm_api('NotificationLog', 'retry', Array)
#8 [internal function]: drush_civicrm_api('NotificationLog...', 'system_log_id=1...', 'debug=1')
#9 /usr/share/php/drush/includes/command.inc(334): call_user_func_array('drush_civicrm_a...', Array)
#10 /usr/share/php/drush/includes/command.inc(208): _drush_invoke_hooks('civicrm-api', Array, 'civicrm')
#11 [internal function]: drush_command('NotificationLog...', 'system_log_id=1...', 'debug=1')
#12 /usr/share/php/drush/includes/command.inc(175): call_user_func_array('drush_command', Array)
#13 /usr/share/php/drush/drush.php(92): drush_dispatch(Array)
#14 /usr/share/php/drush/drush.php(61): _drush_bootstrap_and_dispatch()
#15 /usr/share/php/drush/drush.php(16): drush_main()
#16 {main}
    [is_error] => 1
    [error_message] => Failure: Missing Parameter b
)
Improve this question
11
  • Has the contact's Civi ID changed? Is the Paypal account exactly the same as a year ago?
    – Lesley Carter - BackOffice
    Mar 13, 2019 at 17:17
  • As far as I can tell, no. Are you suggesting a merged contact (or something) may cause this? In the above example the cid = 4729 in CiviCRM which seems to match the IPN. I do not know of any major changes to the Paypal account.
    – Zachary
    Mar 13, 2019 at 17:23
  • There might have been a change in the Paypal IPN URL? Could that be the culprit? It doesn't seem like it, because Civi still has the IPN's in its logs.
    – Zachary
    Mar 13, 2019 at 23:58
  • 1
    Have you seen civicrm-core#659 in CiviCRM's Gitlab? Some debugging steps there may help.
    – Chris Burgess
    Mar 18, 2019 at 3:55
  • 1
    Good odds it was a separate issue (esp if Eileen says so!), just thought the steps to debug from that thread might be useful to you, eg inspecting CiviCRM's debug logs ... And it's often useful to know about other / similar bugs ...
    – Chris Burgess
    Mar 19, 2019 at 22:42

3 Answers 3

Reset to default
2

When troubleshooting IPNs, the most important first step is to see if CiviCRM received them correctly. You can do this by checking the civicrm_system_log database table for the IPNs.

If you are NOT receiving the IPNs in Civi, there is most likely a web server configuration error, or they're being sent to the wrong URL.

If Civi IS receiving the IPNs, you can use the excellent notificationlog extension to replay your IPNs. On replay, you can check your CiviCRM logs for errors, insert debugging code, etc.

Improve this answer
2
  • I updated the OP with the debug from the notificationlog extension.
    – Zachary
    Mar 20, 2019 at 17:19
  • I accepted this answer because it seems like the most generic and plausible way for another person in my spot to move forward.
    – Zachary
    Mar 20, 2019 at 21:41
2

My answer above is generic to this issue; this answer is specifically addressing Zachary. Thanks for posting the backtrace, it's got the details we need.

When you create an ARB (recurring payment) subscription with PayPal, Civi sends some details to PayPal. In return, PayPal embeds those details in every IPN. That's how Civi can match an IPN with the correct contact, membership, etc.

In the last IPN above, it's this part:

"rp_invoice_id":"i=c83d98a31d0e2c2a5cf3173493e24e3b&m=contribute&c=16014&r=830&b=&p="

Note that there are no values for b or p. Your error, not coincidentally, is Missing Parameter b. I have a Troubleshooting PayPal and CiviCRM page on my wiki that says what each letter is for. That same information is available in the file in line #0 in your backtrace.

I can see there that p is OK to be blank. However, the value of b is supposed to be the contribution ID of the first contribution made as part of this recurring series. If you look at my wiki page linked above, you can read how to fix this. You only need to a) look up the appropriate contribution ID; b) add it in PayPal using the instruction in the In PayPal section of the wiki.

That explains how to fix the existing payments that exist! The question that remains is how this happened in the first place. For that, I can't help you; I haven't seen this before. However, I also have no sites running PayPal Pro AND Webform-CiviCRM, so that's a clue. You may want to try to replicate this through webform; very likely though, it's something that was fixed a while ago and you just need to clean up the mess.

PS - to fix IPNs that you can't resend from PayPal, you can also edit the b= value in civicrm_system_log and use the notificationlog extension to replay those successfully.

Improve this answer
1
  • 1
    On all the latest versions so we'll see what happens. Appreciate you walking me through this!
    – Zachary
    Mar 20, 2019 at 20:49
0

Our team ran into a similar issue. Check the permissions on your server. They may have changed after you updated Civi.

Improve this answer
2
  • 1
    Thanks for being part of CiviCRM's Stackexchange! This answer could be a lot more informative if it was more detailed? "Permissions" could mean filesystem permissions, CMS permissions, DB permissions, or something else entirely ...
    – Chris Burgess
    Mar 19, 2019 at 22:44
  • The issue happened before and after the upgrade, but I am open to all suggestions!
    – Zachary
    Mar 20, 2019 at 1:40

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.