by eggsurplus

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 Trial

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 5 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

  1. eggsurplus member avatar

    eggsurplus Provider Affiliate

    5 years ago

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

  2. eggsurplus member avatar

    eggsurplus Provider Affiliate

    5 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 member avatar

      joseblas1 Verified Purchase

      5 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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND users.deleted=0
      Fri Jan 13 12:55:13 2017 [22720][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = 'Users'
                      AND ear.bean_id = '7e73b509-309f-d929-2e9d-572320cab23d'
                      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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND users.deleted=0
      Fri Jan 13 12:55:13 2017 [3145][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = 'Users'
                      AND ear.bean_id = '7e73b509-309f-d929-2e9d-572320cab23d'
                      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. Selección_113.png

      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: Selección_114.png

      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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND users.deleted=0
      Fri Jan 13 12:52:49 2017 [22726][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = 'Users'
                      AND ear.bean_id = '7e73b509-309f-d929-2e9d-572320cab23d'
                      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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND users.deleted=0
      Fri Jan 13 12:52:49 2017 [3145][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = 'Users'
                      AND ear.bean_id = '7e73b509-309f-d929-2e9d-572320cab23d'
                      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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND users.deleted=0
      Fri Jan 13 12:52:50 2017 [22720][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' 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 = 'Users'
                      AND ear.bean_id = '7e73b509-309f-d929-2e9d-572320cab23d'
                      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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND category = 'ETag' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND category = 'ETag' 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 = '7e73b509-309f-d929-2e9d-572320cab23d' AND category = 'ETag' 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`='ETag',`date_modified`='2017-01-13 11:52:50',`assigned_user_id`='7e73b509-309f-d929-2e9d-572320cab23d',`contents`='YToxOntzOjEyOiJtYWluTWVudUVUYWciO2k6MTkzO30='
                           WHERE  user_preferences.id = '7a92bce7-f683-c704-3fe8-572320e0cf65' 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 = 'SecurityGroups' OR rhs_module='SecurityGroups')
      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 = 'SecurityGroups' OR rhs_module='SecurityGroups')
      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 = 'UserPreferences' 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 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 = '1' 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 = '1' 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 = '1' 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='1' AND category = 'global' 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 = '1' 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 = 'Users'
                      AND ear.bean_id = '1'
                      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
      
  3. eggsurplus member avatar

    eggsurplus Provider Affiliate

    5 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?

    • eggsurplus member avatar

      eggsurplus Provider Affiliate

      4 years ago

      Closing this out as it has been quite awhile. I hope that everything has been resolved at this point.

This case is public. Please leave out any sensitive information such as URLs, passwords, etc.
Saving Comment Saving Comment...
Rating
Rating
  • "It is not working. Below error is coming. "Specified directory '' for zip file 'upload://6.5.24_SecuritySuite_v3.1.12.zip' extraction does not exist."" - MaxMobility

    Read More Reviews