7.11.0 upgrade wizard won't open

I’m running 7.11.0 and I want to upgrade to .2. When I click upgrade wizard, the page eventually times out with a 500 Error.

I have tried clearing the upload/upgrades folder. It is recreated, but it doesn’t make a difference.

I confirmed permissions by running
chmod -R 755 .
chmod -R 775 cache custom modules themes data upload config_override.php

Upgradewizard.log only contains the following

Fri, 22 Feb 2019 20:20:59 +0000 [UpgradeWizard] - setting session variables...
Fri, 22 Feb 2019 20:20:59 +0000 [UpgradeWizard] - -----------------------------------------------------------------------------
Fri, 22 Feb 2019 20:20:59 +0000 [UpgradeWizard] - Upgrade started. At start.php
Fri, 22 Feb 2019 20:20:59 +0000 [UpgradeWizard] - at unlinkUWTempFiles()

My php.ini has
max_execution_time = 6000
memory_limit = 256M
max_input_time = 60;
error_reporting = E_ALL & ~E_DEPRECATED & ~E_STRICT & ~E_NOTICE
upload_max_filesize = 64M
post_max_size = 64M

What can I do to troubleshoot?

Check php_errors.log to see exactly what that error 500 is caused by.

Check Admin / Diagnostic / phpinfo to see if your effective values are the ones you listed, or maybe they are not taking effect.

phpinfo will also tell you your php.in path to make sure you’re editing the correct one. Remeber you have to restart your web server for php.ini changes to take effect.

Exact same error for me. I was able to upgrade my test install from 7.10.x to 7.11.2 but can’t do my production version from 7.11.0 to 7.11.2. Did you manage to get it done?

A 500 error is a server crash, so there are a million possible causes for that. So I wouldn’t conclude that the problem is the same just because of being a “500”.

Now, if you can find errors in the logs, especially the web server log, then you start to really diagnose what’s happenning.

Thanks. The diagnostic was useful…I wasn’t updating the correct php.ini file. I have resolved that issue, but I am still having the same issue. Here are the contents of my php error log

[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/ewtwonet/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/ewtwonet/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/ewtwonet/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Warning:  PHP Startup: SourceGuardian: Unable to initialize module
Module compiled with module API=20160303
PHP    compiled with module API=20100525
These options need to match
 in Unknown on line 0
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/username/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/username/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/username/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/username/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:00:03 America/New_York] PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /home1/username/public_html/sugarcrm/modules/ACL/ACLController.php on line 82
[28-Feb-2019 12:06:01 America/New_York] PHP Fatal error:  Uncaught Exception: Database failure. Please refer to suitecrm.log for details. in /home1/username/public_html/sugarcrm/include/utils.php:1775
Stack trace:
#0 /home1/username/public_html/sugarcrm/include/database/DBManager.php(353): sugar_die('Database failur...')
#1 /home1/username/public_html/sugarcrm/include/database/DBManager.php(328): DBManager->registerError('Retrieving reco...', 'Retrieving reco...', true)
#2 /home1/username/public_html/sugarcrm/include/database/MysqliManager.php(179): DBManager->checkError('Retrieving reco...', true)
#3 /home1/username/public_html/sugarcrm/include/database/MysqlManager.php(285): MysqliManager->query('SELECT users.* ...', true, 'Retrieving reco...')
#4 /home1/username/public_html/sugarcrm/data/SugarBean.php(4561): MysqlManager->limitQuery('SELECT users.* ...', 0, 1, true, 'Retrieving reco...')
#5 /home1/username/public_html/sugarcrm/include/SugarObjects/templates/person/Person.php(113): SugarBean->retrieve('1', true, true)
#6 /home1/username/public_html/sugarcrm/module in /home1/username/public_html/sugarcrm/include/utils.php on line 1775

And here is what is in my sugarcrm.log, which is different than what I posted in the OP


Thu Feb 28 14:46:04 2019 [666301][1][FATAL] IP Address mismatch: SESSION IP: 173.xx.xxx.xx CLIENT IP: 75.xxx.xxx.xx
Thu Feb 28 10:10:15 2019 [748735][1][FATAL] Exception handling in /home1/username/public_html/sugarcrm/include/MVC/Controller/SugarController.php:402
Thu Feb 28 10:10:15 2019 [748735][1][FATAL] Exception in Controller: Failed to parse Host URL 'http://'
Thu Feb 28 10:10:15 2019 [748735][1][FATAL] backtrace:
#0 /home1/username/public_html/sugarcrm/lib/Search/ElasticSearch/ElasticSearchClientBuilder.php(177): SuiteCRM\Search\ElasticSearch\ElasticSearchClientBuilder::sanitizeHost(Array)
#1 /home1/username/public_html/sugarcrm/lib/Search/ElasticSearch/ElasticSearchClientBuilder.php(63): SuiteCRM\Search\ElasticSearch\ElasticSearchClientBuilder::loadFromSugarConfig()
#2 /home1/username/public_html/sugarcrm/lib/Search/ElasticSearch/ElasticSearchIndexer.php(86): SuiteCRM\Search\ElasticSearch\ElasticSearchClientBuilder::getClient()
#3 /home1/username/public_html/sugarcrm/lib/Search/ElasticSearch/ElasticSearchIndexer.php(576): SuiteCRM\Search\ElasticSearch\ElasticSearchIndexer->__construct()
#4 /home1/username/public_html/sugarcrm/modules/Administration/repairDatabase.php(179): SuiteCRM\Search\ElasticSearch\ElasticSearchIndexer::repairElasticsearchIndex()
#5 /home1/username/public_html/sugarcrm/modules/Administration/QuickRepairAndRebuild.php(137): include_once('/home1/username...')
#6 /home1/username/public_html/sugarcrm/modules/Administration/QuickRepairAndRebuild.php(121): RepairAndClear->repairDatabase()
#7 /home1/username/public_html/sugarcrm/modules/Administration/views/view.repair.php(61): RepairAndClear->repairAndClearAll(Array, Array, false, true)
#8 /home1/username/public_html/sugarcrm/include/MVC/View/SugarView.php(226): ViewRepair->display()
#9 /home1/username/public_html/sugarcrm/include/MVC/Controller/SugarController.php(432): SugarView->process()
#10 /home1/username/public_html/sugarcrm/include/MVC/Controller/SugarController.php(375): SugarController->processView()
#11 /home1/username/public_html/sugarcrm/include/MVC/SugarApplication.php(109): SugarController->execute()
#12 /home1/username/public_html/sugarcrm/index.php(52): SugarApplication->execute()
#13 {main}
Thu Feb 28 12:06:01 2019 [9084][-none-][FATAL] Mysqli_query failed.
Thu Feb 28 12:06:01 2019 [9084][-none-][FATAL] Retrieving record by id users:1 found  Query Failed: SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 LIMIT 0,1: MySQL error 2006: MySQL server has gone away

Because of the IP mismatch error, I unchecked validate user in system settings. I also cleared my suitecrm.log file and tried to open the Upgrade Wizard with the log file set to Error and then to Fatal. I don’t really see anything useful, do you?

Set to Error:

Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] current_language is: en_us
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCachesMash
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheZend
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheWincache
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheMemcached
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheMemory
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Using cache backend SugarCacheMemory, since 999 is less than 1000
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheRedis
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheAPC
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheMemcache
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Found cache backend SugarCacheFile
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Found language file: en_us.lang.php
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Found extended language file: en_us.lang.ext.php
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Found custom language file: en_us.lang.php
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = 'Active' and deleted = 0
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query Execution Time:0.00090289115905762
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query:SELECT category, name, value FROM config
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query Execution Time:0.00064587593078613
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system'
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query Execution Time:0.00027084350585938
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = '[$ oemail %]'
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query Execution Time:0.00022387504577637
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Hook called: ::after_entry_point
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Including module specific hook file for custom/modules
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Including Ext hook file for custom/application
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Hook called: ::after_session_start
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Unable to find SugarController:: SaveConfig
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] We have an authenticated user id: 1
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Hook called: Users::before_retrieve
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0
Thu Feb 28 13:14:37 2019 [211823][-none-][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 Start: 0 count: 1
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query:SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 LIMIT 0,1
Thu Feb 28 13:14:37 2019 [211823][-none-][INFO] Query Execution Time:0.0093560218811035
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] get_user_array query: SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Query:SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Query Execution Time:0.00059604644775391
Thu Feb 28 13:14:37 2019 [211823][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
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Query Execution Time:0.00043201446533203
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Query:SELECT 
                    ea.email_address,
                    ea.email_address_caps,
                    ea.invalid_email,
                    ea.opt_out,
                    ea.confirm_opt_in,
                    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
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Query Execution Time:0.001227855682373
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] Hook called: Users::after_retrieve
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] FACTOR AUTH: --------------------- CHECK FACTOR AUtH ---------------------
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] FACTOR AUTH: User needs factor auth, request is not Logout
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] FACTOR AUTH: User does`nt need factor auth
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] Current user is: admin
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] Current user is: admin
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] setting cookie ck_login_id_20 to 1
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] setting cookie ck_login_language_20 to en_us
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] current_language is: en_us
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Found language file: en_us.lang.php
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Found extended language file: en_us.lang.ext.php
Thu Feb 28 13:14:37 2019 [211823][1][INFO] Found custom language file: en_us.lang.php
Thu Feb 28 13:14:37 2019 [211823][1][DEBUG] Performing action: action_saveconfig MODULE: Configurator
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Unable to load custom logic file: custom/include/social/hooks.php
Thu Feb 28 13:14:38 2019 [211859][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:41 2019 [211984][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:14:51 2019 [212468][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.
Thu Feb 28 13:16:02 2019 [215387][1][ERROR] Pop error level. Try to remove the error_reporting() function from your code.

No new lines were added to the log after I set it to Fatal.

If you set your log level to FATAL, that means only the highest level of messages will show. If there are none, the log will be empty. Normally when you are troubleshooting you do the opposite, increase the log level to DEBUG to see all messages.

This is the message I believe requires more concern:

Thu Feb 28 12:06:01 2019 [9084][-none-][FATAL] Retrieving record by id users:1 found  Query Failed: SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 LIMIT 0,1: MySQL error 2006: MySQL server has gone away

You’re crashing your database server with a perfectly normal Query, this really shouldn’t be happening…

same issue here, wish i had realized earlier to search for version errors on the forums BEFORE upgrading. Wow.