Email Receipts Not Sent Following Contribution

[Campaigner]

Hi Eileen,

I added your five debug lines into three places in the CRM/Core/Payment/BaseIPN.php file,

Once immediately after:
  function completeTransaction(&$input, &$ids, &$objects, &$transaction, $recur = FALSE) {

Once immediately before:
    CRM_Core_Error::debug_log_message("Contribution record updated successfully");
[I chose this location because the message "Contribution record updated successfully" was appearing in my log files.]

And once immediately after:
      CRM_Core_Error::debug_log_message("Receipt sent");

As of right now, when a contribution gets made, only two sets of new debug log messages appear. (Presumably the ones immediately after "CRM_Core_Error::debug_log_message("Receipt sent");" are not being sent, since the problem we're trying to address is that receipts themselves are not being sent.)

For the two sets of debug log messages, the first set shows "[info] $values is not set", while the second set shows "[info] $values = Array" and then proceeds to show farther down  "[is_email_receipt] => 1"

What other information would be useful from these debug logs to shed light on the problem?

file-wise CRM_Core_Payment_BaseIPN equates to CRM/Core/Payment/BaseIPN.php

If you add some lines like


      CRM_Core_Error::debug_var('values', $values, TRUE, TRUE);
      CRM_Core_Error::debug_var('recur', $recur, TRUE, TRUE);
      CRM_Core_Error::debug_var('objects', $objects, TRUE, TRUE);
      CRM_Core_Error::debug_var('input', $input, TRUE, TRUE);
      CRM_Core_Error::debug_var('ids', $ids, TRUE, TRUE);


then the values will be logged into the log file

e.g right before this line

    CRM_Core_Error::debug_log_message("Success: Database updated");

If seems that $values['is_email_receipt']  is likely to be set to 0

I would probably put the same lines just below

  function completeTransaction(&$input, &$ids, &$objects, &$transaction, $recur = FALSE) {

to see whether it was already  0 at the start of that function

[Eileen]

Hmm - that implies is is actually trying to send the receipt - try adding debug right before & after

      self::sendMail($input, $ids, $objects, $values, $recur, FALSE);

Which will determine if it is failing in that function

(if that is the case w'll have to move the debug into CRM/Contribution/BAO/Contribution.php I think)

You can add lines like

    CRM_Core_Error::debug_log_message("Your text goes here");

to track which lot of debug output you are seeing

[Campaigner]

Well, when I add that sendMail function to each of the lists of five debug statements along with an identifying debug statement as you suggested, the result is that I get a continual loop of messages indicating that the segment immediately after:
  function completeTransaction(&$input, &$ids, &$objects, &$transaction, $recur = FALSE) {
continues to be processed.

This looping perhaps made sense given that we know that $values is not set at that stage of things. So, I took the sendMail function out of that part of the BaseIPN.php file, and that allowed the transaction to move forward to the point where the log shows it got to the functions just before the command to record that the "Contribution record updated successfully". At this point, the log shows a fatal error. I have copied the error and the backtrace below (modifying the backtrace to hide the exact site address).

So, I think that it's now clear that the sendMail function isn't working as it should, and so I'm willing to continue on to CRM/Contribution/BAO/Contribution.php as you suggest.

Thank you.

Fatal error and Backtrace:

Nov 18 04:47:09  [info] $Fatal Error Details = Array
(
    [message] => The requested Profile (gid=) is disabled, OR there is no Profile with that ID, OR a valid 'gid=' integer value is missing from the URL. Contact the site administrator if you need assistance.
   

Code: [Select]

=>
)

Nov 18 04:47:09  [info] $backTrace = #0 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Error.php(320): CRM_Core_Error::backtrace("backTrace", TRUE)
#1 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Profile/Form/Edit.php(120): CRM_Core_Error::fatal("The requested Profile (gid=) is disabled, OR there is no Profile with that ID...")
#2 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Form.php(351): CRM_Profile_Form_Edit->preProcess()
#3 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/QuickForm/Action/Display.php(93): CRM_Core_Form->buildForm()
#4 httpdocs/administrator/components/com_civicrm/civicrm/packages/HTML/QuickForm/Controller.php(203): CRM_Core_QuickForm_Action_Display->perform(Object(CRM_Profile_Form_Edit), "display")
#5 httpdocs/administrator/components/com_civicrm/civicrm/packages/HTML/QuickForm/Page.php(103): HTML_QuickForm_Controller->handle(Object(CRM_Profile_Form_Edit), "display")
#6 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Controller.php(345): HTML_QuickForm_Page->handle("display")
#7 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Utils/Wrapper.php(117): CRM_Core_Controller->run()
#8 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Invoke.php(455): CRM_Utils_Wrapper->run("CRM_Profile_Form_Edit", "Create Profile", (Array:2))
#9 [internal function](): CRM_Core_Invoke::profile((Array:3))
#10 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Invoke.php(289): call_user_func((Array:2), (Array:3))
#11 /httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Invoke.php(72): CRM_Core_Invoke::runItem((Array:14))
#12 httpdocs/administrator/components/com_civicrm/civicrm/CRM/Core/Invoke.php(52): CRM_Core_Invoke::_invoke((Array:3))
#13 httpdocs/components/com_civicrm/civicrm.php(85): CRM_Core_Invoke::invoke((Array:3))
#14 httpdocs/components/com_civicrm/civicrm.php(11): civicrm_invoke()
#15 httpdocs/libraries/joomla/application/component/helper.php(383): require_once("httpdocs/components/com_civicrm/civicrm.php")
#16 httpdocs/libraries/joomla/application/component/helper.php(351): JComponentHelper::executeComponent("httpdocs/components/com_civicrm/civicrm.php")
#17 httpdocs/includes/application.php(197): JComponentHelper::renderComponent("com_civicrm")
#18 httpdocs/index.php(42): JSite->dispatch()
#19 {main}






[quote author=Eileen link=topic=30615.msg131643#msg131643 date=1384747460]
Hmm - that implies is is actually trying to send the receipt - try adding debug right before & after

      self::sendMail($input, $ids, $objects, $values, $recur, FALSE);

Which will determine if it is failing in that function

(if that is the case w'll have to move the debug into CRM/Contribution/BAO/Contribution.php I think)

You can add lines like

    CRM_Core_Error::debug_log_message("Your text goes here");

to track which lot of debug output you are seeing
[/quote]

[Eileen]

Are you sure this latest message is part of this sequence - not a co-incidence? If it were it would point to the profile on the relevant contribution page having been disabled. However, most CiviCRM logs tend to be littered with that message because it occurs whenever someone goes to look at a disabled profile - often the 'someone' is a search engine robot

[Derek]

Was this issue ever solved?  I am experiencing the exact same thing on a CiviCRM 4.5.2 install with Wordpress 4.0.  Outbound email testing works fine and receipt emails can be sent successfully manually.  Automatic receipt emails are not going out, however, despite the option to send the emails being checked for the contribution page.  Perhaps I'm not familiar enough with CiviCRM to tell from reading the thread, but it appears this conversation just died off without ever finding a solution.  Thank you, and apologies for digging up an old thread, but it seems exactly on point to what I'm experiencing now.

[peoute]

Derek, I am experiencing the same issue as well! Glad I'm not crazy.

I just upgraded WP to 4.0 and CiviCRM to 4.5.3 over the weekend and am noticing that our contribution forms are not triggering the normal email receipt.

I also noticed the timestamp for the transaction looked right in CiviCRM, but the receipt time sent in the contribution was off in the future a couple of hours.

I can manually send the receipt, though, and when I do, the timestamp is right.

Code: [Select]

Nov 10 01:18:07  [info] Contribution record updated successfully   \\\first transaction?

Nov 10 01:18:26  [info] returning since contribution has already been handled

Nov 10 13:52:18  [info] Contribution record updated successfully    \\\second transaction attempt?

Nov 10 13:52:30  [info] returning since contribution has already been handled

Nov 10 16:39:50  [info] Amount values dont match between database and IPN request   \\\refund of first transaction in PayPal?

[peoute]

I'm attempting to move the discussion to the upgrade board, since that seems to be the source of the current issue.

http://forum.civicrm.org/index.php/topic,34753.0.html