Any suggestions on debugging this trace?

[EranSch]

Hey Guys,

We're working on getting a menagerie of message templates set up and I'm working on developing a way to test them. I've got some test events set up with scheduled reminders configured to send every day... just so every time I execute a job something should send. The reminders are set on Event Name entities.

I'm using the wp-cli api interface to execute the scheduled job on demand and I'm getting the following trace:

Code: [Select]

Array
(
    [error_code] => syntax error
    [trace] => #0 [internal function]: CRM_Core_Error::exceptionHandler(Object(DB_Error))
#1 /[...]/wp-content/plugins/civicrm/civicrm/packages/PEAR.php(931): call_user_func(Array, Object(DB_Error))
#2 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB.php(975): PEAR_Error->PEAR_Error('DB Error: synta...', -2, 16, Array, 'SELECT e.contac...')
#3 /[...]/wp-content/plugins/civicrm/civicrm/packages/PEAR.php(564): DB_Error->DB_Error(-2, 16, Array, 'SELECT e.contac...')
#4 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/common.php(1905): PEAR->raiseError(NULL, -2, NULL, NULL, 'SELECT e.contac...', 'DB_Error', true)
#5 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/mysql.php(899): DB_common->raiseError(-2, NULL, NULL, NULL, '1064 ** You hav...')
#6 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/mysql.php(328): DB_mysql->mysqlRaiseError()
#7 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/common.php(1216): DB_mysql->simpleQuery('SELECT e.contac...')
#8 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/DataObject.php(2442): DB_common->query('SELECT e.contac...')
#9 /[...]/wp-content/plugins/civicrm/civicrm/packages/DB/DataObject.php(1634): DB_DataObject->_query('SELECT e.contac...')
#10 /[...]/wp-content/plugins/civicrm/civicrm/CRM/Core/DAO.php(325): DB_DataObject->query('SELECT e.contac...')
#11 /[...]/wp-content/plugins/civicrm/civicrm/CRM/Core/DAO.php(1116): CRM_Core_DAO->query('SELECT e.contac...', true)
#12 /[...]/wp-content/plugins/civicrm/civicrm/CRM/Core/BAO/ActionSchedule.php(1276): CRM_Core_DAO::executeQuery('SELECT e.contac...', Array)
#13 /[...]/wp-content/plugins/civicrm/civicrm/CRM/Core/BAO/ActionSchedule.php(1372): CRM_Core_BAO_ActionSchedule::buildRecipientContacts(3, '20141015164059', Array)
#14 /[...]/wp-content/plugins/civicrm/civicrm/api/v3/Job.php(188): CRM_Core_BAO_ActionSchedule::processQueue(NULL, Array)
#15 /[...]/wp-content/plugins/civicrm/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_job_send_reminder(Array)
#16 /[...]/wp-content/plugins/civicrm/civicrm/Civi/API/Kernel.php(95): Civi\API\Provider\MagicFunctionProvider->invoke(Array)
#17 /[...]/wp-content/plugins/civicrm/civicrm/api/api.php(25): Civi\API\Kernel->run('Job', 'send_reminder', Array, NULL)
#18 /[...]/wp-content/plugins/civicrm/wp-cli/civicrm.php(176): civicrm_api('Job', 'send_reminder', Array)
#19 /[...]/wp-content/plugins/civicrm/wp-cli/civicrm.php(137): CiviCRM_Command->api()
#20 [internal function]: CiviCRM_Command->__invoke(Array, Array)
#21 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/WP_CLI/Dispatcher/CommandFactory.php(52): call_user_func(Array, Array, Array)
#22 [internal function]: WP_CLI\Dispatcher\CommandFactory::WP_CLI\Dispatcher\{closure}(Array, Array)
#23 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/WP_CLI/Dispatcher/Subcommand.php(293): call_user_func(Object(Closure), Array, Array)
#24 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/WP_CLI/Runner.php(304): WP_CLI\Dispatcher\Subcommand->invoke(Array, Array, Array)
#25 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/WP_CLI/Runner.php(311): WP_CLI\Runner->run_command(Array, Array)
#26 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/WP_CLI/Runner.php(696): WP_CLI\Runner->_run_command()
#27 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/wp-cli.php(34): WP_CLI\Runner->after_wp_load()
#28 /chroot/wp-cli/vendor/wp-cli/wp-cli/php/boot-fs.php(17): include('/chroot/wp-cli/...')
#29 {main}
    [is_error] => 1
    [error_message] => DB Error: syntax error
)

I've got query logging enabled and it looks like the offending query is as follows:

Code: [Select]

SELECT e.contact_id as contact_id, e.id as entity_id, 'civicrm_participant' as entity_table, 14 as action_schedule_id, MAX(reminder.action_date_time) as latest_log_time
FROM civicrm_participant e
INNER JOIN civicrm_event r ON e.event_id = r.id INNER JOIN civicrm_contact c ON c.id = e.contact_id AND c.is_deleted = 0 AND c.is_deceased = 0
INNER JOIN civicrm_action_log reminder ON reminder.contact_id = e.contact_id AND
reminder.entity_id          = e.id AND
reminder.entity_table       = 'civicrm_participant' AND
reminder.action_schedule_id = 14
WHERE e.role_id IN (5) AND r.id IN (11) AND r.is_active = 1 AND r.is_template = 0  AND e.status_id IN (1,4,5,6,7,9,12,13,16,17,18,22,24,27,28,29,30) AND '20141015165226' <= DATE_ADD(, INTERVAL  )
GROUP BY reminder.contact_id, reminder.entity_id, reminder.entity_table
HAVING TIMEDIFF(20141015165226, latest_log_time) >= TIME(':00:00')

I'm not much of a SQL guy but it looks like the syntax error falls at the end of line 8, DATE_ADD(, INTERVAL  ) perhaps? 

In this case I've only a single reminder set up with a fixed send date of today. Actually, attached is a screenshot of the configuration for the reminder.

Anyone have any thoughts on what might be going on here?

[Dan C]

You are definitely thinking along the right lines, there is something wrong in that DATE_ADD statement.  It appears you are missing the first argument, which is the date itself.  I'm not sure why it is missing though, although there should be other options after the OR in your screen shot which appear to be missing.

[EranSch]

Hey danc, thanks for the reply!

The reason the OR options aren't displayed is because I have a fixed mail date set instead of using a relative date based on event_start. If that's the cause of the syntax error then that certainly seems like a bug in the query building logic.

That said, previous tests using a relative date were also failing. Hopefully I can get some time today and I'll get a good trace/query from that scenario as well.

[Dan C]

Well there is a bug either way then because that OR should disappear with the fields.  Minor but annoying to me (and present in 4.5.2 on the demo site).  Once we know whether there are other issues here I will see about dealing with that though.

[EranSch]

Cool. This is next on my pile so I'll amass some more info now.

Is there an up to date WordPress demo site available yet?

All of the URLs I could find were running an outdated version of WP and the demo credentials we being rejected.

[Dan C]

http://wp45.demo.civicrm.org/ is the current site but it looks like it has been destroyed.  I believe they are suppose to be reset every 36 hours so it should be fixed reasonably soon (although if someone with the ability to fix it sees this please let us know

[EranSch]

Cool. It looks like it's back up. So, two things: The 'OR' text does in fact to continue to display when a fixed date is set. This should be easy enough to resolve.

Second, I was able to reproduce an error condition that seems to be consistent with the other error I was getting. In this case the error message is 'A fatal error was triggered' and the trace is as follows:

Code: [Select]

#0 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/DAO.php(946): CRM_Core_Error::fatal()
#1 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Contribute/BAO/Contribution.php(3357): CRM_Core_DAO::getFieldValue('CRM_Event_BAO_P...', NULL, 'contribution_id', 'participant_id')
#2 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/BAO/ActionSchedule.php(811): CRM_Contribute_BAO_Contribution::getPaymentInfo(NULL, 'event')
#3 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/BAO/ActionSchedule.php(1373): CRM_Core_BAO_ActionSchedule::sendMailings(3, '20141017152347')
#4 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/api/v3/Job.php(188): CRM_Core_BAO_ActionSchedule::processQueue(NULL, Array)
#5 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/Civi/API/Provider/MagicFunctionProvider.php(86): civicrm_api3_job_send_reminder(Array)
#6 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/Civi/API/Kernel.php(95): Civi\\API\\Provider\\MagicFunctionProvider->invoke(Array)
#7 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/api/api.php(25): Civi\\API\\Kernel->run('Job', 'send_reminder', Array, NULL)
#8 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Utils/REST.php(396): civicrm_api('Job', 'send_reminder', Array)
#9 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Utils/REST.php(629): CRM_Utils_REST::process(Array, Array)
#10 [internal function]: CRM_Utils_REST::ajax()
#11 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/Invoke.php(296): call_user_func(Array)
#12 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/Invoke.php(75): CRM_Core_Invoke::runItem(Array)
#13 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm/CRM/Core/Invoke.php(52): CRM_Core_Invoke::_invoke(Array)
#14 /srv/buildkit/build/wp45/wp-content/plugins/civicrm/civicrm.php(506): CRM_Core_Invoke::invoke(Array)
#15 [internal function]: CiviCRM_For_WordPress->invoke('')
#16 /srv/buildkit/build/wp45/wp-includes/plugin.php(429): call_user_func_array(Array, Array)
#17 /srv/buildkit/build/wp45/wp-admin/admin.php(217): do_action('toplevel_page_C...')
#18 {main}

I've attached the configuration as well. I suppose the next step will be to try and debug this into the Civi core and see if I can track the offending query down.

[Dave Greenberg]

You can follow this issue for a fix:
https://issues.civicrm.org/jira/browse/CRM-15481

[EranSch]

Thanks. David!

[Dave Greenberg]

Eran - would be great if you could apply the patch here and see if that fixes your problem. It works on my local sandbox.

https://github.com/civicrm/civicrm-core/pull/4416.patch

[EranSch]

Excellent! I would be happy to. I'll report back with my findings!

[EranSch]

It seems as though this patch has not corrected either failing condition:

• Attempting a scheduled reminder with a fixed send date, I'm getting the DB Error: syntax error - http://pastebin.com/ddkn36ed
• Using a relative send date, I'm still getting the A fatal error was triggered error - http://pastebin.com/2cefK63L

If I comment out line 815 (which invokes getPaymentInfo()) from CRM/Core/BAO/ActionSchedule.php then the later error does not occur.

Would it be beneficial for me to dig up the queries for these errors as well?

[EranSch]

It looks like the work performed by Monish has resolved the issue problem with messages using a relative send date.

Cursory testing so far indicates that messages with fixed send dates may still be failing.

[Dave Greenberg]

Eran - Please let us know ASAP if you're still getting errors. I did test w/ a fixed reminder date - but possibly not the same set of criteria (or possibly a difference in the recipient properties).

Assuming you can recreate it. please get us as much detail as you can including error(s) from the log file and screenshots of the scheduled reminder configuration screen.

You can post those against the issue on the issue tracker (and request that it be reopened):
https://issues.civicrm.org/jira/browse/CRM-15481