IPN for recurring payments only partially working

[nkinkade]

We recently moved our existing install of CiviCRM to a new host, and at the same time upgraded CiviCRM from 1.7 (yikes) to 2.0.3.  Everything seems to be working fine so far, except for PayPal IPN for recurring contributions.  I see in the Apache logs that PayPal is sending the IPN, and at first I thought that it wasn't getting into CiviCRM at all, until I poked around in the database and noticed that the entry in civicrm_contribution_recur actually reflected the latest IPN that was sent by PayPal (with the correct date, processor_id and all), but other than that there appears to be no other trace of the contribution.  CiviCRM.log doesn't seem to reveal anything.

Anyone know of a reason why IPN would only partially work like that?

Thanks,

Nathan

[Donald Lobo]

does CiviCRM.log tell you if the db has been updated etc? PayPalIPN code writes a fair bit of information of that file, so it should give you some trace of what is happening and where

your best bet will be to debug the code at: CRM/Core/Payment/PayPalIPN.php, function recur

lobo

[nkinkade]

Okay, so CiviCRM.log did/does have some useful information.  It would appear that the code is trying to insert a row into the table civicrm_contribution, but without specifying a contact_id, which not only is a required field, but there is also a cascading delete constraint on that field against the civicrm_contact table.  Before I start trying to really dig into this, is there anything obvious that presents itself?  All of the submitted information both GET vars and POSTed data from the IPN is correct.  Here is the specific query and error (Note: I replaced any potentially sensitive data with # symbols):

[debug_info] => INSERT INTO civicrm_contribution (domain_id , contribution_page_id , receive_date , total_amoun
t , fee_amount , net_amount , trxn_id , invoice_id , receipt_date , source , contribution_recur_id , contribution_s
tatus_id ) VALUES ( 1 ,  1 ,  20080809120429 ,  25.00 ,  1.28 ,  23.72 , '############' , '#############' ,
 20080809120429 , 'Online Contribution: Support the Commons' ,  43 ,  1 )  [nativecode=1452 ** Can
not add or update a child row: a foreign key constraint fails (`civicrm/civicrm_contribution`, CONSTRAINT `FK_civic
rm_contribution_contact_id` FOREIGN KEY (`contact_id`) REFERENCES `civicrm_contact` (`id`) ON DELETE CASCADE)]

[Donald Lobo]

does the IPN GET information have the contact ID? The code gets the contact ID from the GET request, so it might be missing there? Was this recurring created in the 1.7 version?

lobo

[nkinkade]

Everything in the GET and POST part of the request was correct.  Yes, the recurring payment was created in v1.7 before we upgraded to 2.0.3  I checked and all of the IDs are the same, and as far as I could tell the GET part of the URL hasn't changed from 1.7 to 2.0.3.  Just so you can see, here is the logged info about the request (again, I've hidden some of the sensitive data):

Aug 09 12:04:29  [info] $GET = Array
(
    [reset] => 1
    [module] => contribute
    [contactID] => 3172
    [contributionID] => 3830
    [contributionTypeID] => 1
    [contributionRecurID] => 43
    [contributionPageID] => 1
)


Aug 09 12:04:29  [info] $POST = Array
(
    [payment_date] => 05:04:25 Aug 09, 2008 PDT
    [txn_type] => subscr_payment
    [subscr_id] => S-****************
    [last_name] => Doe
    [residence_country] => AU
    [item_name] => Online Contribution: Support the Commons
    [payment_gross] => 25.00
    [mc_currency] => USD
    [business] => paypal@creativecommons.org
    [payment_type] => instant
    [verify_sign] => *****************************************
    [payer_status] => unverified
    [payer_email] => john@doe.gov
    [txn_id] => *******************
    [receiver_email] => paypal@creativecommons.org
    [first_name] => John
    [invoice] => ***************************
    [payer_id] => *************
    [receiver_id] => **************
    [payment_status] => Completed
    [payment_fee] => 1.28
    [mc_fee] => 1.28
    [mc_gross] => 25.00
    [charset] => windows-1252
    [notify_version] => 2.4
)

[Donald Lobo]

can you get on IRC and we can figure out how to debug there.

might be easier if i can get ssh access to the box

thanx

lobo

[nkinkade]

I'm posting here as a follow up.  I poked around PayPalIPN.php and noticed that there was a direct reference to $contactID on line 150, yet register_globals is turned off and the variable had no value, so many things that were relying on $contribution->contact_id were failing.  Donald Lobo looked into this and verified it as a bug.  The fix is to change line #150 from:

$contribution->contact_id = $contactID;

to:

$contribution->contact_id = $ids['contact'];

Thanks to Donald for being so responsive and helping me to solve this issue.

[Donald Lobo]

this issue has been filed and fixed at: http://issues.civicrm.org/jira/browse/CRM-3395

it will be part of v2.0.6 (and 2.1)

lobo