[Vtigercrm-developers] Event Handler broken [Solved]

[Alan Lord]

On 29/11/12 17:22, Prasad wrote:
> Alan,
>
> Can you please share a test case / hint of reproducing the bug.
> If you have a setup where we can review that would useful too.

Hi Prasad,

I've been doing some more testing this morning.

This is how I'm registering the Event Handler:

require('include/events/include.inc');
require_once('include/utils/utils.php');
global $adb;
$em = new VTEventsManager($adb);
$em->unregisterHandler('CompaniesHandler');
$em->registerHandler('vtiger.entity.aftersave',
   'modules/Companies/CompaniesHandler.php',
   'CompaniesHandler',
   "moduleName in ['Companies', 'Quotes', 'SalesOrder', 'Invoice']"
);

And it all seems fine in the vtiger_eventhandlers table. In the "cond" 
field is the following text:

moduleName in ['Companies', 'Quotes', 'SalesOrder', 'Invoice']

I've tried replacing ' with ", removing ' and removing the [] but all 
cause severe failures.

However with the cond string as above, saving an *Account* record fails 
with the error described in my original post. And I don't think the 
CompaniesHandler Class isn't even called. The log stops before it gets 
there.

Here are the final few lines of the log file when this happens:
Fri Nov 30 10:06:40 2012,537 [7721] DEBUG index - Exiting is_admin 
method ...
Fri Nov 30 10:06:40 2012,537 [7721] DEBUG index - Prepared sql query 
being executed : select * from vtiger_ws_entity where name=?
Fri Nov 30 10:06:40 2012,537 [7721] DEBUG index - Prepared sql query 
parameters : [Users]
Fri Nov 30 10:06:40 2012,538 [7721] DEBUG user - Entering Users() method ...
Fri Nov 30 10:06:40 2012,538 [7721] DEBUG index - Entering 
getColumnFields(Users) method ...
Fri Nov 30 10:06:40 2012,538 [7721] DEBUG index - in getColumnFields Users
Fri Nov 30 10:06:40 2012,538 [7721] DEBUG index - Entering 
getTabid(Users) method ...
Fri Nov 30 10:06:40 2012,538 [7721] DEBUG index - Exiting getTabid 
method ...
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG index - Exiting 
getColumnFields method ...
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG user - Exiting Users() method ...
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG index - Entering 
getTabid(Users) method ...
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG index - Exiting getTabid 
method ...
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG index - Prepared sql query 
being executed : select * from vtiger_users where id=? and deleted=0 and 
status='Active'
Fri Nov 30 10:06:40 2012,539 [7721] DEBUG index - Prepared sql query 
parameters : [1]
Fri Nov 30 10:06:40 2012,540 [7721] DEBUG index - Prepared sql query 
being executed : select groupname from vtiger_groups where groupid = ?
Fri Nov 30 10:06:40 2012,540 [7721] DEBUG index - Prepared sql query 
parameters : [1]
Fri Nov 30 10:06:40 2012,540 [7721] DEBUG index - Prepared sql query 
being executed : select first_name from vtiger_users where id = ?
Fri Nov 30 10:06:40 2012,540 [7721] DEBUG index - Prepared sql query 
parameters : [1]
Fri Nov 30 10:06:40 2012,541 [7721] DEBUG index - Prepared sql query 
being executed : select name from vtiger_ws_entity where id=?
Fri Nov 30 10:06:40 2012,541 [7721] DEBUG index - Prepared sql query 
parameters : [11]
Fri Nov 30 10:06:40 2012,542 [7721] INFO VT - PearDatabase ->ADODB 
getColumnNames table=com_vtiger_workflows
Fri Nov 30 10:06:40 2012,543 [7721] DEBUG index - Prepared sql query 
being executed : select workflow_id, module_name, summary, test, 
execution_condition, defaultworkflow, type
 
  from com_vtiger_workflows where module_name=?
Fri Nov 30 10:06:40 2012,543 [7721] DEBUG index - Prepared sql query 
parameters : [Accounts]
Fri Nov 30 10:06:40 2012,544 [7721] DEBUG index - Prepared sql query 
being executed : SELECT * FROM com_vtiger_workflow_activatedonce
                                                         WHERE 
entity_id=? and workflow_id=?
Fri Nov 30 10:06:40 2012,544 [7721] DEBUG index - Prepared sql query 
parameters : [14,2]
Fri Nov 30 10:06:40 2012,545 [7721] DEBUG index - Prepared sql query 
being executed : SELECT * FROM com_vtiger_workflowtasks
                                                         INNER JOIN 
com_vtiger_workflowtask_queue
                                                         ON 
com_vtiger_workflowtasks.task_id= com_vtiger_workflowtask_queue.task_id
                                                         WHERE 
workflow_id=? AND entity_id=?
Fri Nov 30 10:06:40 2012,545 [7721] DEBUG index - Prepared sql query 
parameters : [2,14]

(That final query returns an empty result set)

And that is it. It stops there with the:

Fatal error: Uncaught exception 'Exception' with message 'Deadlock 
occured for events: CompaniesHandler' in 
/var/www/vtigercrm/include/events/VTEventTrigger.inc:155 Stack trace: #0 
/var/www/vtigercrm/include/events/VTEventsManager.inc(118): 
VTEventTrigger->trigger(Object(VTEntityData)) #1 
/var/www/vtigercrm/data/CRMEntity.php(812): 
VTEventsManager->triggerEvent('vtiger.entity.a...', 
Object(VTEntityData)) #2 
/var/www/vtigercrm/modules/Accounts/Save.php(103): 
CRMEntity->save('Accounts') #3 /var/www/vtigercrm/index.php(749): 
include('/var/www/vtigercrm/mo...') #4 {main} thrown in 
/var/www/vtigercrm/include/events/VTEventTrigger.inc on line 155

Removing the string entirely from the "cond" field and everything works 
again.

hope that helps.

Al

--
Libertus Solutions
http://www.libertus.co.uk