SecuritySuite - SuiteCRM and CE Teams

Control what your users can access and save time, money, and frustrations. Lock down sensitive data in SugarCRM or SuiteCRM to specific groups or teams. Supports unlimited assigned users, unlimited group assignments to records, custom layouts for each group, login/sudo capabilities and much more.

Free 30 day trial

Try it Now

By clicking you consent to share your profile with the developer

#2797 - Module Builder crash in 7.7.8

Closed Bug? created by joseblas1 Verified Purchase 7 years ago

Hi,

since I migrate from suiteCRM 7.5 (sugar version 6.5.23) to 7.7.8 (sugar version 6.5.24) I can not deploy any package in the Module Builder.

If I disable the SecuritySuite for a moment, I can publish and deploy packages if any error, but if I enable again this plugin, the error continues.

Is there any conflict?

How to reproduce it? 1. Install SecuritySuite 6.5.24 2. Go to module builder and create a new package with a new module 3. Try to publish (blank screen) or deploy (alert error message)

Thanks

eggsurplus Provider Affiliate
7 years ago

Thanks for the steps to reproduce. I'm looking into it and will report back. Hopefully with a fix.

reply

eggsurplus Provider Affiliate

7 years ago

I'm unable to reproduce the problem thus far. What does the alert error message say? Do you see anything errors at the time that you try to publish in suitecrm.log or your PHP error log? What version of PHP are you running? Are PHP Notices turned off? Is Strict Standards disabled?

joseblas1 Verified Purchase

7 years ago

Hi,

My PHP version is PHP 5.3.10-1ubuntu3.21 (fpm-fcgi) (built: Oct 28 2015 01:47:51)

When I try to: * publish a module: I directly have a blank screen. Any error in the logs:

Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] current_language is: en_us
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Hook called: ::after_session_start
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] We have an authenticated user id: 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Hook called: Users::before_retrieve
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0
Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 Start: 0 count: 1
Fri Jan 13 12:55:13 2017 [22720][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 LIMIT 0,1
Fri Jan 13 12:55:13 2017 [22720][-none-][INFO] Query Execution Time:0.00014996528625488
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; and u1.deleted=0
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:7.5101852416992E-5
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00016212463378906
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: Users::after_retrieve
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_id_20 to 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_language_20 to en_us
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] current_language is: en_us
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Performing action: action_savepackage MODULE: ModuleBuilder
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/language
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/Dashlets
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/Dashlets/test_testDashlet
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/metadata
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/metadata/subpanels
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:55:13 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] current_language is: en_us
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Hook called: ::after_session_start
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] We have an authenticated user id: 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Hook called: Users::before_retrieve
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0
Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 Start: 0 count: 1
Fri Jan 13 12:55:13 2017 [3145][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 LIMIT 0,1
Fri Jan 13 12:55:13 2017 [3145][-none-][INFO] Query Execution Time:0.0001380443572998
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; and u1.deleted=0
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:6.4849853515625E-5
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00012612342834473
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: Users::after_retrieve
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_id_20 to 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_language_20 to en_us
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] current_language is: en_us
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Performing action: action_buildpackage MODULE: ModuleBuilder
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: saving relationships to custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:55:13 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()

create a new module: Alert error message with no text.

Any error in the logs:

Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Performing action: action_savemodule MODULE: ModuleBuilder
Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test
Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:48:31 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()

deploy a module: Alert error. See picture:

And this is the log:

Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Performing action: action_savepackage MODULE: ModuleBuilder
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/language
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/Dashlets
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/Dashlets/test_testDashlet
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/metadata
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] MBModule.php->renameMetaData: new_dir=custom/modulebuilder/packages/test/modules/test/metadata/subpanels
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:52:49 2017 [3146][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] current_language is: en_us
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Hook called: ::after_session_start
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] We have an authenticated user id: 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Hook called: Users::before_retrieve
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0
Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 Start: 0 count: 1
Fri Jan 13 12:52:49 2017 [22726][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 LIMIT 0,1
Fri Jan 13 12:52:49 2017 [22726][-none-][INFO] Query Execution Time:0.00017094612121582
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; and u1.deleted=0
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00011301040649414
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.0001521110534668
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: Users::after_retrieve
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXX
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXX
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_id_20 to 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_language_20 to en_us
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] current_language is: en_us
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Using Action View Map:displaydeploy
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ModuleBuilder::after_ui_frame
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class VersionCheck without parameters
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::after_ui_footer
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:52:49 2017 [22726][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] current_language is: en_us
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Hook called: ::after_session_start
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] We have an authenticated user id: 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Hook called: Users::before_retrieve
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0
Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 Start: 0 count: 1
Fri Jan 13 12:52:49 2017 [3145][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 LIMIT 0,1
Fri Jan 13 12:52:49 2017 [3145][-none-][INFO] Query Execution Time:0.00017213821411133
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; and u1.deleted=0
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:6.6995620727539E-5
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00018596649169922
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: Users::after_retrieve
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_id_20 to 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_language_20 to en_us
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] current_language is: en_us
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Using Action View Map:displaydeploy
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ModuleBuilder::after_ui_frame
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class VersionCheck without parameters
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::after_ui_footer
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:52:49 2017 [3145][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] current_language is: en_us
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Hook called: ::after_session_start
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] We have an authenticated user id: 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Hook called: Users::before_retrieve
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0
Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 Start: 0 count: 1
Fri Jan 13 12:52:50 2017 [22720][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND users.deleted=0 LIMIT 0,1
Fri Jan 13 12:52:50 2017 [22720][-none-][INFO] Query Execution Time:0.00014209747314453
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; and u1.deleted=0
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:7.5101852416992E-5
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00011610984802246
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: Users::after_retrieve
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Current user is: XXXX
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_id_20 to 7e73b509-309f-d929-2e9d-572320cab23d
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] setting cookie ck_login_language_20 to en_us
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] current_language is: en_us
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] ModuleBuilderController:
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Performing action: action_deploypackage MODULE: ModuleBuilder
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: loading relationships from custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] UndeployedRelationships: saving relationships to custom/modulebuilder/packages/test/modules/test/relationships.php
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: ::server_round_trip
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Saving Preferences to DB XXXX
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Saving Preferences to DB: XXXX
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Retrieve UserPreference: SELECT user_preferences.* FROM user_preferences  WHERE assigned_user_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND category = &#039;ETag&#039; AND deleted=0
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Limit Query:SELECT user_preferences.* FROM user_preferences  WHERE assigned_user_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND category = &#039;ETag&#039; AND deleted=0 Start: 0 count: 1
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT user_preferences.* FROM user_preferences  WHERE assigned_user_id = &#039;7e73b509-309f-d929-2e9d-572320cab23d&#039; AND category = &#039;ETag&#039; AND deleted=0 LIMIT 0,1
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.0011131763458252
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: UserPreferences::before_save
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class NotifyAssignment without parameters
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:UPDATE user_preferences
                    SET `category`=&#039;ETag&#039;,`date_modified`=&#039;2017-01-13 11:52:50&#039;,`assigned_user_id`=&#039;7e73b509-309f-d929-2e9d-572320cab23d&#039;,`contents`=&#039;YToxOntzOjEyOiJtYWluTWVudUVUYWciO2k6MTkzO30=&#039;
                     WHERE  user_preferences.id = &#039;7a92bce7-f683-c704-3fe8-572320e0cf65&#039; AND deleted=0
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00031495094299316
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEPRECATED] PHP4 Style Constructors are deprecated and will be remove in 7.8, please update your code
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:7.6055526733398E-5
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Hook called: UserPreferences::after_save
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = &#039;UserPreferences&#039; AND aow_workflow.status = &#039;Active&#039; AND (aow_workflow.run_when = &#039;Always&#039; OR aow_workflow.run_when = &#039;On_Save&#039; OR aow_workflow.run_when = &#039;Create&#039;) AND aow_workflow.deleted = 0 
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][INFO] Query Execution Time:0.00012707710266113
Fri Jan 13 12:52:50 2017 [22720][7e73b509-309f-d929-2e9d-572320cab23d][DEBUG] Calling MySQLi::disconnect()
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] current_language is: en_us
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Using cache backend SugarCacheMemcached, since 900 is less than 1000
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheZend
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheFile
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCachesMash
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Hook called: ::after_entry_point
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Including module specific hook file for custom/modules
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Including Ext hook file for custom/application
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Hook called: Users::before_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][-none-][INFO] Query Execution Time:0.00013089179992676
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Loading Preferences DB Charles
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT contents FROM user_preferences WHERE assigned_user_id=&#039;1&#039; AND category = &#039;global&#039; AND deleted = 0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00056886672973633
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;1&#039; and u1.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.6041946411133E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;1&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00014185905456543
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Users::after_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] --------------------------------------------> at cron.php <--------------------------------------------
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Using SugarCronJobs as CRON driver
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM job_queue WHERE status=&#039;running&#039; AND date_modified <= &#039;2017-01-12 11:53:02&#039;
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00054693222045898
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] get_full_list:  order_by = &#039;&#039; and where = &#039;schedulers.status=&#039;Active&#039; AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!=&#039;done&#039;)&#039;
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SugarBean[Scheduler].load_relationships, Loading relationship (created_by_link).
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SugarBean[Scheduler].load_relationships, Loading relationship (modified_user_link).
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list_query: query is  SELECT  schedulers.*  , jt0.user_name created_by_name , jt0.created_by created_by_name_owner  , &#039;Users&#039; created_by_name_mod , jt1.user_name modified_by_name , jt1.created_by modified_by_name_owner  , &#039;Users&#039; modified_by_name_mod FROM schedulers   LEFT JOIN  users jt0 ON jt0.id=schedulers.created_by AND jt0.deleted=0
 AND jt0.deleted=0  LEFT JOIN  users jt1 ON schedulers.modified_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where (schedulers.status=&#039;Active&#039; AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!=&#039;done&#039;)) AND schedulers.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query: SELECT  schedulers.*  , jt0.user_name created_by_name , jt0.created_by created_by_name_owner  , &#039;Users&#039; created_by_name_mod , jt1.user_name modified_by_name , jt1.created_by modified_by_name_owner  , &#039;Users&#039; modified_by_name_mod FROM schedulers   LEFT JOIN  users jt0 ON jt0.id=schedulers.created_by AND jt0.deleted=0
 AND jt0.deleted=0  LEFT JOIN  users jt1 ON schedulers.modified_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where (schedulers.status=&#039;Active&#039; AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!=&#039;done&#039;)) AND schedulers.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.0011861324310303
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list_query: result is mysqli_result Object
(
    [current_field] => 0
    [field_count] => 22
    [lengths] => 
    [num_rows] => 1
    [type] => 0
)

Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): id = 183509ea-d8c2-cc62-46b3-5836bdf89415
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): deleted = 0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): date_entered = 2016-11-24 10:14:59
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): date_modified = 2016-11-24 10:28:20
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): created_by = 7e73b509-309f-d929-2e9d-572320cab23d
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): created_by_name = XXXX
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): modified_user_id = 7e73b509-309f-d929-2e9d-572320cab23d
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): modified_by_name = XXXX
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): name = Process workflows
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): job = function::processAOW_Workflow
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): date_time_start = 2005-01-01 10:15:00
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): job_interval = */2::*::*::*::*
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): last_run = 2016-11-30 11:22:01
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): status = Active
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] process_full_list: Scheduler(183509ea-d8c2-cc62-46b3-5836bdf89415): catch_up = 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Schedulers::process_record
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] -----> Scheduler found [ 1 ] ACTIVE jobs
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->Schedulers->deriveDBDateTimes() got an object of type: Scheduler
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->got * day
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->got * months
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->got * dates
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->got * hours
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Constraints: start: 2005-01-01 10:15:00 from: 1970-01-01 00:00:00 end: 2017-01-14 11:53:03 to: 2017-01-14 11:53:03 now: 2017-01-13 11:53:02
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] ----->Scheduler found valid job (Process workflows) for time GMT(2017-01-13 11:53:00)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Get One: |SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039;|
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039; Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039; LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00011587142944336
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Users::before_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.8902969360352E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;1&#039; and u1.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:5.3882598876953E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;1&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:7.5101852416992E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Users::after_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Get One: |SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039;|
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039; Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM users WHERE id = &#039;1&#039; AND is_admin = 1 AND deleted = 0 AND status = &#039;Active&#039; LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.6041946411133E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Users::before_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT users.* FROM users  WHERE users.id = &#039;1&#039; AND users.deleted=0 LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:7.7962875366211E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = &#039;1&#039; and u1.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:5.1021575927734E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = &#039;Users&#039;
                AND ear.bean_id = &#039;1&#039;
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.1988830566406E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: Users::after_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::before_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class NotifyAssignment without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:INSERT INTO job_queue (assigned_user_id,id,name,deleted,date_entered,date_modified,scheduler_id,execute_time,status,resolution,target,requeue,job_delay,client)
                    VALUES (&#039;1&#039;,&#039;28426fab-0a67-d70b-c91f-5878bff89eb8&#039;,&#039;Process workflows&#039;,0,&#039;2017-01-13 11:53:02&#039;,&#039;2017-01-13 11:53:02&#039;,&#039;183509ea-d8c2-cc62-46b3-5836bdf89415&#039;,&#039;2017-01-13 11:53:02&#039;,&#039;queued&#039;,&#039;queued&#039;,&#039;function::processAOW_Workflow&#039;,0,0,&#039;&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00044608116149902
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] PHP4 Style Constructors are deprecated and will be remove in 7.8, please update your code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:8.392333984375E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] PHP4 Style Constructors are deprecated and will be remove in 7.8, please update your code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:5.6982040405273E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::after_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = &#039;SchedulersJobs&#039; AND aow_workflow.status = &#039;Active&#039; AND (aow_workflow.run_when = &#039;Always&#039; OR aow_workflow.run_when = &#039;On_Save&#039; OR aow_workflow.run_when = &#039;Create&#039;) AND aow_workflow.deleted = 0 
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.0001220703125
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Get One: |SELECT id FROM job_queue WHERE execute_time <= &#039;2017-01-13 11:53:02&#039; AND status = &#039;queued&#039; ORDER BY date_entered ASC|
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT id FROM job_queue WHERE execute_time <= &#039;2017-01-13 11:53:02&#039; AND status = &#039;queued&#039; ORDER BY date_entered ASC Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM job_queue WHERE execute_time <= &#039;2017-01-13 11:53:02&#039; AND status = &#039;queued&#039; ORDER BY date_entered ASC LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00053191184997559
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::before_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Retrieve SchedulersJob : SELECT job_queue.* FROM job_queue  WHERE job_queue.id = &#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND job_queue.deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Limit Query:SELECT job_queue.* FROM job_queue  WHERE job_queue.id = &#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND job_queue.deleted=0 Start: 0 count: 1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT job_queue.* FROM job_queue  WHERE job_queue.id = &#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND job_queue.deleted=0 LIMIT 0,1
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00023102760314941
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::after_retrieve
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:UPDATE job_queue SET status=&#039;running&#039;, date_modified=&#039;2017-01-13 11:53:02&#039;, client=&#039;CRONd64b270d0590008071628a407630e471:5208&#039; WHERE id=&#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND status=&#039;queued&#039;
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00065493583679199
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] Formatting correction: SchedulersJobs->date_entered had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] Formatting correction: SchedulersJobs->date_modified had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] Formatting correction: SchedulersJobs->execute_time had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::before_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class NotifyAssignment without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:UPDATE job_queue
                    SET `assigned_user_id`=&#039;1&#039;,`name`=&#039;Clean Jobs Queue&#039;,`date_modified`=&#039;2017-01-13 11:53:02&#039;,`scheduler_id`=&#039;9e4913d4-392b-c461-e268-5836c18edbff&#039;,`execute_time`=&#039;2017-01-13 11:52:00&#039;,`status`=&#039;running&#039;,`resolution`=&#039;queued&#039;,`message`=NULL,`target`=&#039;function::cleanJobQueue&#039;,`data`=NULL,`requeue`=0,`retry_count`=NULL,`failure_count`=NULL,`job_delay`=0,`client`=&#039;CRONd64b270d0590008071628a407630e471:5208&#039;,`percent_complete`=NULL
                     WHERE  job_queue.id = &#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00021195411682129
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] PHP4 Style Constructors are deprecated and will be remove in 7.8, please update your code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.0081481933594E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::after_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = &#039;SchedulersJobs&#039; AND aow_workflow.status = &#039;Active&#039; AND (aow_workflow.run_when = &#039;Always&#039; OR aow_workflow.run_when = &#039;On_Save&#039; OR aow_workflow.run_when = &#039;Create&#039;) AND aow_workflow.deleted = 0 
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:8.0108642578125E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Custom add jobs here loaded
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: ::server_round_trip
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Calling MySQLi::disconnect()
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][FATAL] Job ca25399e-4558-bbaa-3dd7-5878bff91b02 (Clean Jobs Queue) failed in CRON run
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Resolving job ca25399e-4558-bbaa-3dd7-5878bff91b02 as failure: Unexpected failure, please check PHP logs and suitecrm.log
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::job_failure
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] Formatting correction: SchedulersJobs->failure_count had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::before_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class NotifyAssignment without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:UPDATE job_queue
                    SET `assigned_user_id`=&#039;1&#039;,`name`=&#039;Clean Jobs Queue&#039;,`date_modified`=&#039;2017-01-13 11:53:02&#039;,`scheduler_id`=&#039;9e4913d4-392b-c461-e268-5836c18edbff&#039;,`execute_time`=&#039;2017-01-13 11:52:00&#039;,`status`=&#039;done&#039;,`resolution`=&#039;failure&#039;,`message`=&#039;Unexpected failure, please check PHP logs and suitecrm.log\n&#039;,`target`=&#039;function::cleanJobQueue&#039;,`data`=NULL,`requeue`=0,`retry_count`=NULL,`failure_count`=1,`job_delay`=0,`client`=&#039;CRONd64b270d0590008071628a407630e471:5208&#039;,`percent_complete`=NULL
                     WHERE  job_queue.id = &#039;ca25399e-4558-bbaa-3dd7-5878bff91b02&#039; AND deleted=0
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:0.00072598457336426
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEPRECATED] PHP4 Style Constructors are deprecated and will be remove in 7.8, please update your code
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = &#039;SecurityGroups&#039; OR rhs_module=&#039;SecurityGroups&#039;)
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:6.8902969360352E-5
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Hook called: SchedulersJobs::after_save
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class setupCNLogic without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AssignGroups without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = &#039;SchedulersJobs&#039; AND aow_workflow.status = &#039;Active&#039; AND (aow_workflow.run_when = &#039;Always&#039; OR aow_workflow.run_when = &#039;On_Save&#039; OR aow_workflow.run_when = &#039;Create&#039;) AND aow_workflow.deleted = 0 
Fri 13 Jan 2017 12:53:02 PM CET [5208][1][INFO] Query Execution Time:8.0108642578125E-5

eggsurplus Provider Affiliate
7 years ago

Everything looks fine in the logs there. My best guess is that the MB deployer/publisher is running into file permission issues. For that I suggest this script: http://www.shanedowling.com/sugarcrm-permissions-script/

In addition to that, I suggest checking the browser console to see what is being returned via the AJAX request when you try to deploy/publish. There may be something useful in that returned HTML.

Do you see anything in the PHP error logs?

reply
- eggsurplus Provider Affiliate
  7 years ago
  
  Closing this out as it has been quite awhile. I hope that everything has been resolved at this point.
  
  reply

This case is public. Please leave out any sensitive information such as URLs, passwords, etc.

Saving Comment...

SecuritySuite - SuiteCRM and CE Teams

#2797 - Module Builder crash in 7.7.8

"SecuritySuite was a very good addition to our SugarCRM implementation helping to integrate different functional teams with strictly specified roles."

Other Add-Ons of interest

Upsert® Call Center for Dialpad

Survey Rocket for SugarCRM

Microsoft GP Integration - SYNC by Commercient

ADD-ONS

SOLUTIONS

RESOURCES

ABOUT