How can I log Calculated Field activity?

Question

Hi,

Can anyone suggest where in SugarCRM code I might be able to place debugging code to see calculated field activity when a record is modified? Basically, when I modify a record, I want to dump out any fields and any related record fields that are recalculated.

I have an on-demand instance that is giving a 500 error when deleting a record, but I cannot reproduce the error locally. Sugar support said the on-demand instance is running out of memory in small chunks, possibly due to the cascading effect of related records having calculated fields updated. Hence I want to see what's going on.

Thanks

Gary.

Gary Smart · Accepted Answer

Thanks for the suggestion.

I retrieved a backup of the on-demand instance, and I can reproduce the issue on my laptop. I did further investigations, found what I believe to be the issue, and tested a fix on my laptop.

I do have a question (at end of text) about whether it's safe to have this performed on the on-demand instance.

Here is the investigation process do it's documented -

Step 1

I added the following to config_override.php, but it has made no difference.

$sugar_config['disable_related_calc_fields'] = true;

I believe it confirms my thoughts that it is not related to calculated fields.

Step 2

I disabled all logic hooks across all modules and this made no difference too.

Step 3

Turning debugging on to "info" and in sugarcrm.log, I get the following output over-and-over until the 500 error and a php log error PHP Fatal error: Allowed memory size of 1073741824 bytes exhausted (the source file is random). Note that the that the activity id is always the same.

Mon Dec 12 13:17:55 2016 [20298][1][INFO] fetch OneOffset: |SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e15e6e-6fe8-11e6-8049-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e15e6e-6fe8-11e6-8049-060beac1348b' AND activities.deleted=0| Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query:SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e15e6e-6fe8-11e6-8049-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e15e6e-6fe8-11e6-8049-060beac1348b' AND activities.deleted=0 LIMIT 0,1 Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query Execution Time:0.00367712974548 Mon Dec 12 13:17:55 2016 [20298][1][INFO] fetch OneOffset: |SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e60514-70a0-11e6-a054-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e60514-70a0-11e6-a054-060beac1348b' AND activities.deleted=0| Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query:SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e60514-70a0-11e6-a054-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e60514-70a0-11e6-a054-060beac1348b' AND activities.deleted=0 LIMIT 0,1 Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query Execution Time:0.00113797187805 Mon Dec 12 13:17:55 2016 [20298][1][INFO] fetch OneOffset: |SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e7d5c0-6faa-11e6-9f77-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e7d5c0-6faa-11e6-9f77-060beac1348b' AND activities.deleted=0| Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query:SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7e7d5c0-6faa-11e6-9f77-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7e7d5c0-6faa-11e6-9f77-060beac1348b' AND activities.deleted=0 LIMIT 0,1 Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query Execution Time:0.00097393989563 Mon Dec 12 13:17:55 2016 [20298][1][INFO] fetch OneOffset: |SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7ea7cca-7082-11e6-ac60-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7ea7cca-7082-11e6-ac60-060beac1348b' AND activities.deleted=0| Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query:SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = 'f7ea7cca-7082-11e6-ac60-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = 'f7ea7cca-7082-11e6-ac60-060beac1348b' AND activities.deleted=0 LIMIT 0,1 Mon Dec 12 13:17:55 2016 [20298][1][INFO] Query Execution Time:0.00101208686829 :SELECT activities.* , users_cbu.first_name cbu_first_name, users_cbu.last_name cbu_last_name, users_mbu.first_name mbu_first_name, users_mbu.last_name mbu_last_name, sf.id AS my_favorite FROM activities  LEFT JOIN users users_cbu ON users_cbu.id = activities.created_by LEFT JOIN users users_mbu ON users_mbu.id = activities.modified_user_id LEFT JOIN sugarfavorites sf ON sf.deleted = 0 AND sf.module = 'Activities' AND sf.record_id = '9fe746aa-6f80-11e6-92a0-060beac1348b' AND sf.assigned_user_id = '1'  WHERE activities.id = '9fe746aa-6f80-11e6-92a0-060beac1348b' AND activities.deleted=0 LIMIT 0,1

On querying this activity, I see is has something to do with the mail server connection being dead "Delivery Status Notification (Failure)", which is a known issue and has been for over 6 months - (the CRM implementation was delayed so it never got rectified, The project has only just been picked up again.).

mysql> select * from activities where id = '9fe746aa-6f80-11e6-92a0-060beac1348b' \G *************************** 1. row ***************************               id: 9fe746aa-6f80-11e6-92a0-060beac1348b     date_entered: 2016-08-31 13:41:24    date_modified: 2016-08-31 13:41:24 modified_user_id: 1       created_by: 1          deleted: 0        parent_id: 184e8af6-6b38-11e6-bf0e-0275d4b83f51      parent_type: Accounts    activity_type: link             data: {"object":{"name":"Organisation A","type":"Account","module":"Accounts","id":"184e8af6-6b38-11e6-bf0e-0275d4b83f51"},"subject":{"name":"Delivery Status Notification (Failure)","type":"Case","module":"Cases","id":"40856b9a-6b2c-11e6-ab40-060beac1348b"},"link":"cases","relationship":"account_cases"}    comment_count: 0     last_comment: {"name":"","deleted":false,"data":[]} 1 row in set (0.00 sec)

I am not sure how all the mail server errors being logged somewhere all relate back to a single record in the activity table. Any enlightenment would be appreciated to solve my curiosity.

Resolution

On my dev instance, I deleted all activity (DELETE FROM activities; DELETE FROM activities_users;), then successfully could delete the Account record.

I expect other records in other modules to experience the same problem when someone tries to delete them.