Workflow action email related field contacts:contact fails

Workflow on ā€œcase updateā€ modules, when case updated the actions is to send email to (To, Related Field, Contact: Contact) and another email to (To, Related Field, Users: Assigned to). The email to Assigned to works but the email to contact fails. No errors in the logs. Any one know what the issue or how to debug it.

Using 7.10.4

The workflow processing audit lists the contact email as failed. Where to look to find reason for not sending email to contacts:contact?

Have you looked at suitecrm.log to see if thereā€™s anything there?

What is the exact message you get in the audit?

nothing pops up in the suitecrm.log.

the workflow view ā€œprocess auditā€ section shows status Failed & Record shows update text & date created shows current date

https://pasteboard.co/HmOlLti.png
https://pasteboard.co/HmOm8sg.png

I donā€™t know how to help any further if there is no way for us to gather more information. Maybe increase your log level ( in Admin / system settings) to Debug and see if get any thing else in the forums.

Also, try sending to that email, outside the workflow, to see if you can get some error message.

Changed the log level from Fatal to debug:

Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][ERROR] fromUser: Conversion of 2018-05-25 15:30:15 from user format m/d/Y h:ia failed

It doesnā€™t let me attached a file here so I can paste the whole debug trace.

Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] current_language is: en_us
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Using cache backend SugarCacheMemory, since 999 is less than 1000
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheZend
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCachesMash
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheFile
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Found language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Found custom language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = 'Active' and deleted = 0
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query Execution Time:0.00032687187194824
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query:SELECT category, name, value FROM config
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query Execution Time:0.0002601146697998
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query Execution Time:0.00014209747314453
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query Execution Time:0.00019288063049316
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Hook called: ::after_entry_point
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Including module specific hook file for custom/modules
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Including Ext hook file for custom/application
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Hook called: ::after_session_start
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Unable to find SugarController:: Save
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] We have an authenticated user id: 5f866ce7-1b02-0489-040b-5978c66ca7d6
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Hook called: Users::before_retrieve
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0
Fri May 25 10:30:15 2018 [18386][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][-none-][INFO] Query Execution Time:0.00024318695068359
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] get_user_array query: SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00020909309387207
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' and u1.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017714500427246
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00036501884460449
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Users::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: --------------------- CHECK FACTOR AUtH ---------------------
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: User needs factor auth, request is not Logout
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: User does`nt need factor auth
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Current user is: jamal
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Current user is: jamal
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] setting cookie ck_login_id_20 to 5f866ce7-1b02-0489-040b-5978c66ca7d6
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] setting cookie ck_login_language_20 to en_us
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] current_language is: en_us
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Found language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Found custom language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Including module specific hook file for custom/modules/Cases
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve Case : SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00022506713867188
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT acc.id, acc.name FROM accounts  acc, cases  WHERE acc.id = cases.account_id AND cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 AND acc.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00019311904907227
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (cases_created_contact).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases_created_contact)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Performing pre_action
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarController:: performing pre_save.
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: groupHasAccess select count(securitygroups.id) as results from securitygroups inner join securitygroups_users on securitygroups.id = securitygroups_users.securitygroup_id and securitygroups_users.deleted = 0   and securitygroups_users.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' inner join securitygroups_records on securitygroups.id = securitygroups_records.securitygroup_id and securitygroups_records.deleted = 0   and securitygroups_records.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5'   and securitygroups_records.module = 'Cases' where securitygroups.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:select count(securitygroups.id) as results from securitygroups inner join securitygroups_users on securitygroups.id = securitygroups_users.securitygroup_id and securitygroups_users.deleted = 0   and securitygroups_users.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' inner join securitygroups_records on securitygroups.id = securitygroups_records.securitygroup_id and securitygroups_records.deleted = 0   and securitygroups_records.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5'   and securitygroups_records.module = 'Cases' where securitygroups.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00032711029052734
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Performing action: action_save MODULE: Cases
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] Formatting correction: Cases->date_entered had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] Formatting correction: Cases->date_modified had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] save_relationship_changes(): From relationship_field array - adding a relationship record: accounts = 2ba34d45-81f8-ba8e-584a-5a75183131e7
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (accounts).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Accounts::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Including module specific hook file for custom/modules/Accounts
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve Account : SELECT accounts.*,accounts_cstm.* FROM accounts  LEFT JOIN accounts_cstm ON accounts.id = accounts_cstm.id_c  WHERE accounts.id = '2ba34d45-81f8-ba8e-584a-5a75183131e7' AND accounts.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT accounts.*,accounts_cstm.* FROM accounts  LEFT JOIN accounts_cstm ON accounts.id = accounts_cstm.id_c  WHERE accounts.id = '2ba34d45-81f8-ba8e-584a-5a75183131e7' AND accounts.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT accounts.*,accounts_cstm.* FROM accounts  LEFT JOIN accounts_cstm ON accounts.id = accounts_cstm.id_c  WHERE accounts.id = '2ba34d45-81f8-ba8e-584a-5a75183131e7' AND accounts.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00037503242492676
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT a1.name from accounts a1, accounts a2 where a1.id = a2.parent_id and a2.id = '2ba34d45-81f8-ba8e-584a-5a75183131e7' and a1.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017213821411133
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Account].load_relationships, Loading relationship (member_of).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Account].load_relationships, Loading relationship (campaign_accounts).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00032281875610352
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Accounts::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (accounts).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Account].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM cases WHERE cases.account_id = '2ba34d45-81f8-ba8e-584a-5a75183131e7' AND cases.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00019598007202148
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Accounts::before_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Accounts::after_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AccountsJjwg_MapsLogicHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT category, name, value FROM config WHERE category = 'jjwg'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00016593933105469
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00013184547424316
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014901161193848
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CasesJjwg_MapsLogicHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT category, name, value FROM config WHERE category = 'jjwg'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014710426330566
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00013208389282227
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014305114746094
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseFeed without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOP_Case_Updates].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOP_Case_Updates].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOP_Case_Updates].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:	SELECT * FROM relationships
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00066804885864258
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOP_Case_Updates::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO aop_case_updates (id,name,date_entered,date_modified,modified_user_id,created_by,description,deleted,assigned_user_id,case_id,internal)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0014650821685791
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0004119873046875
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0003819465637207
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00039386749267578
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00040912628173828
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT category, name, value FROM config WHERE category = 'tracker'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017189979553223
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOP_Case_Updates::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_Index::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOD_Index : SELECT aod_index.* FROM aod_index  WHERE aod_index.id = '1' AND aod_index.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aod_index.* FROM aod_index  WHERE aod_index.id = '1' AND aod_index.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aod_index.* FROM aod_index  WHERE aod_index.id = '1' AND aod_index.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0001671314239502
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_Index].load_relationships, Loading relationship (assigned_user_id).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (assigned_user_id)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_Index].load_relationships, Loading relationship (assigned_user_id).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (assigned_user_id)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_Index::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOP_Case_Updates::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOP_Case_Updates : SELECT aop_case_updates.* FROM aop_case_updates  WHERE aop_case_updates.id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND aop_case_updates.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aop_case_updates.* FROM aop_case_updates  WHERE aop_case_updates.id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND aop_case_updates.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aop_case_updates.* FROM aop_case_updates  WHERE aop_case_updates.id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND aop_case_updates.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0001678466796875
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id ,cases.name as case_name , cases.assigned_user_id owner FROM cases WHERE deleted=0 AND id='b4e800db-bd91-06ac-168b-5aeefc6211c5'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00015616416931152
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOP_Case_Updates].load_relationships, Loading relationship (contacts_aop_case_updates).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (contacts_aop_case_updates)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOP_Case_Updates::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] get_full_list:  order_by = '' and where = 'aod_indexevent.record_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND aod_indexevent.record_module = 'AOP_Case_Updates''
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (modified_user_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (created_by_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (assigned_user_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list_query: query is  SELECT  aod_indexevent.*  , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner  , 'Users' modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner  , 'Users' assigned_user_name_mod FROM aod_indexevent   LEFT JOIN  users jt0 ON aod_indexevent.modified_user_id=jt0.id AND jt0.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query: SELECT  aod_indexevent.*  , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner  , 'Users' modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner  , 'Users' assigned_user_name_mod FROM aod_indexevent   LEFT JOIN  users jt0 ON aod_indexevent.modified_user_id=jt0.id AND jt0.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00046682357788086
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list_query: result is mysqli_result Object
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:	SELECT * FROM relationships
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00072813034057617
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_IndexEvent::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO aod_indexevent (id,name,date_entered,date_modified,modified_user_id,created_by,deleted,success,record_id,record_module)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0014209747314453
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00055789947509766
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00039911270141602
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00039386749267578
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_IndexEvent::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'AOD_IndexEvent' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00028491020202637
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'AOP_Case_Updates' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00020003318786621
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_WorkFlow::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_WorkFlow : SELECT aow_workflow.* FROM aow_workflow  WHERE aow_workflow.id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND aow_workflow.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_workflow.* FROM aow_workflow  WHERE aow_workflow.id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND aow_workflow.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_workflow.* FROM aow_workflow  WHERE aow_workflow.id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND aow_workflow.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017189979553223
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_WorkFlow::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_Processed: SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00048112869262695
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][ERROR] fromUser: Conversion of 2018-05-25 15:30:15 from user format m/d/Y h:ia failed
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][ERROR] fromUser: Conversion of 2018-05-25 15:30:15 from user format m/d/Y h:ia failed
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_conditions WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND deleted = 0 ORDER BY condition_order ASC
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00028491020202637
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Conditions::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_Condition : SELECT aow_conditions.* FROM aow_conditions  WHERE aow_conditions.id = '7e66a763-43c8-72f8-ead1-5aeef42b2c70' AND aow_conditions.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_conditions.* FROM aow_conditions  WHERE aow_conditions.id = '7e66a763-43c8-72f8-ead1-5aeef42b2c70' AND aow_conditions.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_conditions.* FROM aow_conditions  WHERE aow_conditions.id = '7e66a763-43c8-72f8-ead1-5aeef42b2c70' AND aow_conditions.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00016903877258301
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Conditions::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_Processed: SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_processed.* FROM aow_processed  WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND parent_id = 'cc300417-ed3e-338b-eb03-5b082c832717' AND deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00022411346435547
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:	SELECT * FROM relationships
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00072598457336426
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO aow_processed (id,name,date_entered,date_modified,modified_user_id,created_by,deleted,aow_workflow_id,parent_id,parent_type,status)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.001176118850708
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00039005279541016
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00040411949157715
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00039505958557129
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'AOW_Processed' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00023007392883301
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (aow_actions).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_actions WHERE aow_workflow_id = '81413e73-036c-c8a8-231e-5aeef0b9cdfd' AND deleted = 0 ORDER BY action_order ASC
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0004270076751709
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_Action : SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017213821411133
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Get One: |select id from aow_processed_aow_actions where aow_processed_id = 'd2f6dab6-86db-7ab6-f3d0-5b082c963c6e' AND aow_action_id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND status = 'Complete'|
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:select id from aow_processed_aow_actions where aow_processed_id = 'd2f6dab6-86db-7ab6-f3d0-5b082c963c6e' AND aow_action_id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND status = 'Complete' Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:select id from aow_processed_aow_actions where aow_processed_id = 'd2f6dab6-86db-7ab6-f3d0-5b082c963c6e' AND aow_action_id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND status = 'Complete' LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00034499168395996
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: EmailTemplates::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve EmailTemplate : SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '2bcda35b-9a53-00a6-9091-5a80feace4be' AND email_templates.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '2bcda35b-9a53-00a6-9091-5a80feace4be' AND email_templates.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '2bcda35b-9a53-00a6-9091-5a80feace4be' AND email_templates.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00030398368835449
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: EmailTemplates::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT ea.email_address FROM email_addresses ea
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT ea.email_address FROM email_addresses ea
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00026202201843262
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve AOW_Action : SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT aow_actions.* FROM aow_actions  WHERE aow_actions.id = 'd96b2ca7-2419-3f1f-1408-5aef3b2c0123' AND aow_actions.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00015711784362793
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Action].load_relationships, Loading relationship (aow_processed).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::before_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::before_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT * FROM aow_processed_aow_actions WHERE aow_processed_id='d2f6dab6-86db-7ab6-f3d0-5b082c963c6e' AND aow_action_id='d96b2ca7-2419-3f1f-1408-5aef3b2c0123'  AND deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0001981258392334
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO aow_processed_aow_actions (id,aow_processed_id,aow_action_id,status,date_modified,deleted) VALUES ('d4fc4454-b41d-951e-7ac3-5b082c617cf8','d2f6dab6-86db-7ab6-f3d0-5b082c963c6e','d96b2ca7-2419-3f1f-1408-5aef3b2c0123','Failed','2018-05-25 15:30:15','0')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0013759136199951
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::after_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Actions::after_relationship_add
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOW_Processed].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:	SELECT * FROM relationships
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00065898895263672
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:UPDATE aow_processed
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0011260509490967
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOW_Processed::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'AOW_Processed' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00022578239440918
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: EmailTemplates::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve EmailTemplate : SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '259ab2a5-c48b-1fbc-ceeb-5981f3fe6596' AND email_templates.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '259ab2a5-c48b-1fbc-ceeb-5981f3fe6596' AND email_templates.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT email_templates.* FROM email_templates  WHERE email_templates.id = '259ab2a5-c48b-1fbc-ceeb-5981f3fe6596' AND email_templates.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00015401840209961
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseEventsHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve Case : SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00017881393432617
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT acc.id, acc.name FROM accounts  acc, cases  WHERE acc.id = cases.account_id AND cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 AND acc.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00023198127746582
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (cases_created_contact).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases_created_contact)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CasesJjwg_MapsLogicHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT category, name, value FROM config WHERE category = 'jjwg'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00019192695617676
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00013589859008789
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014781951904297
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:UPDATE cases
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0012340545654297
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = 'SecurityGroups' OR rhs_module='SecurityGroups')
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00045299530029297
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: Inherit from Assigned: INSERT INTO securitygroups_records(id,securitygroup_id,record_id,module,date_modified,deleted) SELECT DISTINCT  uuid() ,u.securitygroup_id,'b4e800db-bd91-06ac-168b-5aeefc6211c5','Cases',CURDATE(),0 from securitygroups_users u inner join securitygroups g on u.securitygroup_id = g.id and g.deleted = 0 and (g.noninheritable is null or g.noninheritable <> 1) left join securitygroups_records d on d.securitygroup_id = u.securitygroup_id and d.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' and d.module = 'Cases' and d.deleted = 0 where d.id is null and u.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' and u.deleted = 0  and (u.noninheritable is null or u.noninheritable <> 1)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO securitygroups_records(id,securitygroup_id,record_id,module,date_modified,deleted) SELECT DISTINCT  uuid() ,u.securitygroup_id,'b4e800db-bd91-06ac-168b-5aeefc6211c5','Cases',CURDATE(),0 from securitygroups_users u inner join securitygroups g on u.securitygroup_id = g.id and g.deleted = 0 and (g.noninheritable is null or g.noninheritable <> 1) left join securitygroups_records d on d.securitygroup_id = u.securitygroup_id and d.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' and d.module = 'Cases' and d.deleted = 0 where d.id is null and u.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' and u.deleted = 0  and (u.noninheritable is null or u.noninheritable <> 1)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00053501129150391
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CasesJjwg_MapsLogicHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT category, name, value FROM config WHERE category = 'jjwg'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014996528625488
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00012302398681641
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00014281272888184
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve Case : SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00018596649169922
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT acc.id, acc.name FROM accounts  acc, cases  WHERE acc.id = cases.account_id AND cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 AND acc.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00019311904907227
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (cases_created_contact).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases_created_contact)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_retrieve
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] get_full_list:  order_by = '' and where = 'aod_indexevent.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND aod_indexevent.record_module = 'Cases''
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (modified_user_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (created_by_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (assigned_user_link).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list_query: query is  SELECT  aod_indexevent.*  , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner  , 'Users' modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner  , 'Users' assigned_user_name_mod FROM aod_indexevent   LEFT JOIN  users jt0 ON aod_indexevent.modified_user_id=jt0.id AND jt0.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query: SELECT  aod_indexevent.*  , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner  , 'Users' modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner  , 'Users' assigned_user_name_mod FROM aod_indexevent   LEFT JOIN  users jt0 ON aod_indexevent.modified_user_id=jt0.id AND jt0.deleted=0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00040197372436523
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list_query: result is mysqli_result Object
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): id = 2c10a23f-e95e-5dbd-46ec-5aeefce3f237
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): name = Test case update 3
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): date_entered = 2018-05-06 12:58:59
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): date_modified = 2018-05-25 12:19:12
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): modified_user_id = 5f866ce7-1b02-0489-040b-5978c66ca7d6
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): modified_by_name = jamal
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): created_by = 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): created_by_name = admin
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): deleted = 0
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): assigned_user_id = 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): success = 1
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): record_id = b4e800db-bd91-06ac-168b-5aeefc6211c5
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] process_full_list: AOD_IndexEvent(2c10a23f-e95e-5dbd-46ec-5aeefce3f237): record_module = Cases
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_IndexEvent::process_record
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (Cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (Cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[AOD_IndexEvent].load_relationships, Loading relationship (cases).
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases)
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:	SELECT * FROM relationships
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00093293190002441
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_IndexEvent::before_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:UPDATE aod_indexevent
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0015349388122559
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: AOD_IndexEvent::after_save
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'AOD_IndexEvent' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00025606155395508
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Auditing: createAuditRecord was not called, audit record will not be created.
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'Cases' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00022506713867188
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Auditing: createAuditRecord was not called, audit record will not be created.
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Performing post_action
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: ::server_round_trip
Fri May 25 10:30:15 2018 [18386][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Calling MySQLi::disconnect()
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] current_language is: en_us
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Using cache backend SugarCacheMemory, since 999 is less than 1000
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheZend
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCachesMash
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheFile
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Found language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Found custom language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = 'Active' and deleted = 0
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query Execution Time:0.0003511905670166
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query:SELECT category, name, value FROM config
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query Execution Time:0.00023818016052246
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query Execution Time:0.00013303756713867
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = '68adf809-54af-42a7-a02d-5974d159fb15'
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query Execution Time:0.00018787384033203
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Hook called: ::after_entry_point
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Including module specific hook file for custom/modules
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Including Ext hook file for custom/application
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Hook called: ::after_session_start
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Unable to find SugarController:: DetailView
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] We have an authenticated user id: 5f866ce7-1b02-0489-040b-5978c66ca7d6
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Hook called: Users::before_retrieve
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0
Fri May 25 10:30:15 2018 [18387][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND users.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18387][-none-][INFO] Query Execution Time:0.00027704238891602
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] get_user_array query: SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0002589225769043
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' and u1.deleted=0
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00020503997802734
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT 
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00037813186645508
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Users::after_retrieve
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: --------------------- CHECK FACTOR AUtH ---------------------
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: User needs factor auth, request is not Logout
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] FACTOR AUTH: User does`nt need factor auth
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Current user is: jamal
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Current user is: jamal
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] setting cookie ck_login_id_20 to 5f866ce7-1b02-0489-040b-5978c66ca7d6
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] setting cookie ck_login_language_20 to en_us
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] current_language is: en_us
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Found language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Found custom language file: en_us.lang.php
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::before_retrieve
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Including module specific hook file for custom/modules/Cases
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Retrieve Case : SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 Start: 0 count: 1
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT cases.* FROM cases  WHERE cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 LIMIT 0,1
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00022101402282715
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT acc.id, acc.name FROM accounts  acc, cases  WHERE acc.id = cases.account_id AND cases.id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5' AND cases.deleted=0 AND acc.deleted=0
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00020599365234375
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean[Case].load_relationships, Loading relationship (cases_created_contact).
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (cases_created_contact)
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Hook called: Cases::after_retrieve
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Creating new instance of hook class CaseUpdatesHook without parameters
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Using Action View Map:detail
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SecuritySuite: groupHasAccess select count(securitygroups.id) as results from securitygroups inner join securitygroups_users on securitygroups.id = securitygroups_users.securitygroup_id and securitygroups_users.deleted = 0   and securitygroups_users.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' inner join securitygroups_records on securitygroups.id = securitygroups_records.securitygroup_id and securitygroups_records.deleted = 0   and securitygroups_records.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5'   and securitygroups_records.module = 'Cases' where securitygroups.deleted = 0 
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:select count(securitygroups.id) as results from securitygroups inner join securitygroups_users on securitygroups.id = securitygroups_users.securitygroup_id and securitygroups_users.deleted = 0   and securitygroups_users.user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' inner join securitygroups_records on securitygroups.id = securitygroups_records.securitygroup_id and securitygroups_records.deleted = 0   and securitygroups_records.record_id = 'b4e800db-bd91-06ac-168b-5aeefc6211c5'   and securitygroups_records.module = 'Cases' where securitygroups.deleted = 0 
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0003659725189209
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:INSERT INTO tracker (monitor_id,user_id,module_name,item_id,item_summary,date_modified,action,session_id,visible ) VALUES ( 'ee9f3095-980e-4fe1-564b-5b082c580cdf','5f866ce7-1b02-0489-040b-5978c66ca7d6','Cases','b4e800db-bd91-06ac-168b-5aeefc6211c5','Test case update 3','2018-05-25 15:30:15','detailview','mhmeteq1alic80tb4ckmtej1g5','1')
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0014309883117676
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT parent_id, parent_type FROM favorites WHERE assigned_user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND deleted = 0 ORDER BY date_entered DESC
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.00029206275939941
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] Limit Query:SELECT item_id, item_summary, module_name, id FROM tracker WHERE id = (SELECT MAX(id) as id FROM tracker WHERE user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND deleted = 0 AND visible = 1) Start: 0 count: 50
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:SELECT item_id, item_summary, module_name, id FROM tracker WHERE id = (SELECT MAX(id) as id FROM tracker WHERE user_id = '5f866ce7-1b02-0489-040b-5978c66ca7d6' AND deleted = 0 AND visible = 1) LIMIT 0,50
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.0019099712371826
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query:DELETE FROM tracker where id = '15915'
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Query Execution Time:0.012476921081543
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][INFO] Tracker: retrieving 10 items
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create_Contact_Vcard.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create_Lead_Vcard.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image View_Create_Email_Templates.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image View_Email_Templates.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image View_Diagnostics.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create_Person_Form.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Schedule_Meeting.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Schedule_Call.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Create.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Today.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Schedule_Call.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image Schedule_Meeting.gif not found
Fri May 25 10:30:15 2018 [18387][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Image List.gif not found

I donā€™t see anything too relevant in there, sorry.

Iā€™m not sure that conversion error is really the source of your problem, doesnā€™t look like it. Lots of people see that error.

Does it behave differently with the ā€œRepeated runsā€ on or off?

No, same failed status with repeated run on or off

is the Related Field -> Contacts: Contact correct? that is the only related contacts to select.

After a lot of searching still canā€™t figure out why the same workflow action for email to related field contacts:contact fails but it works for related field users:assigned to. Any one has this issue?

Note, I can send email to the contact from outside the workflow fine.

It is too bad that when workflow action fails, it doesnā€™t tell much other than status = failed.

I am quite lost and running out of ideas to help you. :frowning:

Maybe you could try variations: a different email, and make sure you are not getting blocked by the ā€œconfirmed opt inā€ mechanismā€¦

I noticed this warning pops up when workflow runs to send the email. Does mean any thing?

Tue May 29 20:00:42 2018 [19806][5f866ce7-1b02-0489-040b-5978c66ca7d6][WARN] Email ID is Empty

Not sure what this validation code does?

./modules/Emails/include/displayEmailAddressOptInField.php: $log->warn(ā€˜Email ID is Emptyā€™);

function displayEmailAddressOptInField(Email $focus, $field, $value, $view)
{
    global $app_strings;
    $log = LoggerManager::getLogger();

    $addressField = 'from_name';

    if (empty($focus->id)) {
        $log = LoggerManager::getLogger();
        $log->warn('Email ID is Empty');
        return '';
    }

Note, Opt In Setting -> Disabled

Please add this line right before the log->warn line

array_walk(debug_backtrace(),create_function('$a,$b','print "{$a[\'function\']}()(".basename($a[\'file\']).":{$a[\'line\']}); ";'));

And get me the output from that (I hope it will show on screen) so I can know where that function is being called from when it gives that error.

I donā€™t think that warning is the issue as I have seen it recently popping up in logs w/o case update to trigger it.

I took a debug log and here what I found, can this be the reason cate update to contacts email fails? this shows several times in the log repeated, not sure if it is retries.

SugarBean[AOP_Case_Updates].load_relationships, Loading relationship (contacts_aop_case_updates).

Wed May 30 20:18:07 2018 [32726][5f866ce7-1b02-0489-040b-5978c66ca7d6][DEBUG] SugarBean.load_relationships, failed Loading relationship (contacts_aop_case_updates)

Try Admin / Repair / Repair relationships

Also Admin /Repair / Quick Repair and Rebuild, scroll to the bottom, press button to sync vardefs if it appears there.

Did all of that and still fails.