Error after upgrading from 8.4.0 to 8.5.0 - no login possible anymore

BastianHammer commented 8 months ago

After a (seemingly successfull) upgrade from 8.4.0 to 8.5.0, whilst still being logged in, I ran the quick repair. It still showed 8.4 version on the about page. Then I used a different browser and I wasn't able to login.

Issue

The spinner icon won't go away and I'm not able to login anymore.

Expected Behavior

I should be able to login and use the CRM.

Actual Behavior

In the browser console, I see the error: message : "no elements in sequence" name : "EmptyError"

The upgrade seemed to be fine:

sudo -u www-data ./bin/console suitecrm:app:upgrade -t "suitecrm-8-5-0"
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Attribute\AttributeBag::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 134
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Attribute\AttributeBag::count() should either be compatible with Countable::count(): int, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 144
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Session::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 131
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Session::count() should either be compatible with Countable::count(): int, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 141

SuiteCRM Upgrade
============

Running: backup-original-modules
step: backup-original-modules | status: done
Successfully backed up files
Running: check-package
step: check-package | status: done
Package found in path
Running: extract-package
step: extract-package | status: done
Package extracted
Running: check-permissions
step: check-permissions | status: done
Permissions checked
Running: install-upgrade-package
step: install-upgrade-package | status: done
Successfully installed package
Running: clear-symfony-cache
step: clear-symfony-cache | status: done
Successfully cleared cache

sudo -u www-data ./bin/console suitecrm:app:upgrade-finalize -t "suitecrm-8-5-0" -m override
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Attribute\AttributeBag::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 134
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Attribute\AttributeBag::count() should either be compatible with Countable::count(): int, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 144
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Session::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 131
PHP Deprecated:  Return type of Symfony\Component\HttpFoundation\Session\Session::count() should either be compatible with Countable::count(): int, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 141

SuiteCRM Finalize Upgrade 
============

Running: legacy-post-upgrade
libpng warning: iCCP: known incorrect sRGB profile
libpng warning: Interlace handling should be turned on when using png_read_image
libpng warning: Interlace handling should be turned on when using png_read_image
libpng warning: iCCP: known incorrect sRGB profile
libpng warning: Interlace handling should be turned on when using png_read_image
libpng warning: iCCP: known incorrect sRGB profile
libpng warning: Interlace handling should be turned on when using png_read_image
libpng warning: iCCP: known incorrect sRGB profile
libpng warning: Interlace handling should be turned on when using png_read_image
step: legacy-post-upgrade | status: done
Post Upgrade process complete
Running: add-new-config-entries
step: add-new-config-entries | status: done
Added new config entries to config file
Running: metadata-merge
step: metadata-merge | status: done
Metadata successfully merged
Running: run-migrations
step: run-migrations | status: done
Successfully run migrations
Running: finalize-clear-symfony-cache
step: finalize-clear-symfony-cache | status: done
Successfully cleared cache
Warning! Please re-set permissions after this upgrade step has completed

The last lines of the upgrade.log

Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - database repaired
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - Start rebuild relationships.
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - End rebuild relationships.
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - Begin merge_config_si_settings
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - End merge_config_si_settings
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - Begin upgrade_connectors
Sat, 30 Dec 2023 10:24:47 +0100 [UpgradeWizard] - End upgrade_connectors
Sat, 30 Dec 2023 10:24:49 +0100 [UpgradeWizard] - Potential PHP generated error messages: 
Sat, 30 Dec 2023 10:24:49 +0100 [UpgradeWizard] - Upgrade completed successfully.
[2023-12-30 10:24:49] upgrade.INFO: step: legacy-post-upgrade | status: done [] []
[2023-12-30 10:24:49] upgrade.INFO: step: legacy-post-upgrade | messages: [] []
[2023-12-30 10:24:49] upgrade.INFO: Post Upgrade process complete [] []
[2023-12-30 10:24:49] upgrade.INFO: step: legacy-post-upgrade | debug: [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check default permissions . [] []
[2023-12-30 10:24:49] upgrade.INFO: end check default permissions . [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check logger settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check logger settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check lead conversion settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: end check lead conversion settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check resource settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: begin check resource settings . [] []
[2023-12-30 10:24:49] upgrade.INFO: Call deleteCache [] []
[2023-12-30 10:24:49] upgrade.INFO: Upgrading user preferences start . [] []
[2023-12-30 10:24:49] upgrade.INFO: Upgrading user preferences finish . [] []
[2023-12-30 10:24:49] upgrade.INFO: Call deleteCache [] []
[2023-12-30 10:24:49] upgrade.INFO: About to repair the database. [] []
[2023-12-30 10:24:49] upgrade.INFO: Running sql:/* Table : inbound_email */ /*COLUMNS*/ /*MISSING IN DATABASE - email_body_filtering -  ROW*/ /* INDEXES */ ALTER TABLE inbound_email   add COLUMN `email_body_filtering` varchar(255)  DEFAULT 'multi' NULL   [] []
[2023-12-30 10:24:49] upgrade.INFO: Running sql:/* Table : saved_search */ /*COLUMNS*/ /*MISSING IN DATABASE - quick_filter -  ROW*/ /* INDEXES */ ALTER TABLE saved_search   add COLUMN `quick_filter` bool  DEFAULT '0' NULL   [] []
[2023-12-30 10:24:49] upgrade.INFO: /* Table : cache_rebuild */ /* MISSING TABLE: cache_rebuild */ CREATE TABLE cache_rebuild (`cache_key` varchar(255)  NULL ,`rebuild` bool  NULL  ) CHARACTER SET utf8 COLLATE utf8_general_ci  [] []
[2023-12-30 10:24:49] upgrade.INFO: database repaired [] []
[2023-12-30 10:24:49] upgrade.INFO: Start rebuild relationships. [] []
[2023-12-30 10:24:49] upgrade.INFO: End rebuild relationships. [] []
[2023-12-30 10:24:49] upgrade.INFO: Begin merge_config_si_settings [] []
[2023-12-30 10:24:49] upgrade.INFO: End merge_config_si_settings [] []
[2023-12-30 10:24:49] upgrade.INFO: Begin upgrade_connectors [] []
[2023-12-30 10:24:49] upgrade.INFO: End upgrade_connectors [] []
[2023-12-30 10:24:49] upgrade.INFO: Potential PHP generated error messages:  [] []
[2023-12-30 10:24:49] upgrade.INFO: Upgrade completed successfully. [] []
[2023-12-30 10:24:49] upgrade.INFO: Running step: add-new-config-entries [] []
[2023-12-30 10:24:49] upgrade.INFO: step: add-new-config-entries | status: done [] []
[2023-12-30 10:24:49] upgrade.INFO: step: add-new-config-entries | messages: [] []
[2023-12-30 10:24:49] upgrade.INFO: Added new config entries to config file [] []
[2023-12-30 10:24:49] upgrade.INFO: step: add-new-config-entries | debug: [] []
[2023-12-30 10:24:49] upgrade.INFO: Adding entry default_charset [] []
[2023-12-30 10:24:49] upgrade.INFO: Adding entry valid_imap_ports [] []
[2023-12-30 10:24:49] upgrade.INFO: Running step: metadata-merge [] []
[2023-12-30 10:24:49] upgrade.INFO: step: metadata-merge | status: done [] []
[2023-12-30 10:24:49] upgrade.INFO: step: metadata-merge | messages: [] []
[2023-12-30 10:24:49] upgrade.INFO: Metadata successfully merged [] []
[2023-12-30 10:24:49] upgrade.INFO: step: metadata-merge | debug: no debug info [] []
[2023-12-30 10:24:49] upgrade.INFO: Running step: run-migrations [] []
[2023-12-30 10:24:49] upgrade.INFO: .env already contains LOCK_DSN. Skipping update. [] []
[2023-12-30 10:24:49] upgrade.INFO: AUTH_TYPE already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: LDAP CONFIG already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: LDAP AUTO CREATE CONFIG already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: SAML CONFIG already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: LOGIN_THROTTLING_MAX_ATTEMPTS already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: SAML auto create option already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: LOGIN_THROTTLING_INTERVAL already in .env, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: DefaultExt extension already exists, skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: "defaultExt" extension does not exist on the extracted upgrade package (path: "/var/www/domain/service.domain/tmp/package/upgrade/SuiteCRM-8.5.0-extracted/extensions/defaultExt") , skipping. [] []
[2023-12-30 10:24:49] upgrade.INFO: Removed PDF from allowed_preview inside config file. [] []
[2023-12-30 10:24:49] upgrade.INFO: step: run-migrations | status: done [] []
[2023-12-30 10:24:49] upgrade.INFO: step: run-migrations | messages: [] []
[2023-12-30 10:24:49] upgrade.INFO: Successfully run migrations [] []
[2023-12-30 10:24:49] upgrade.INFO: step: run-migrations | debug: [] []
[2023-12-30 10:24:49] upgrade.INFO: 10:24:49 WARNING   [app] Migration App\Migrations\Version20200608135040 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20200608135040"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20220907112919 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20220907112919"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20220912082608 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20220912082608"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20221003150202 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20221003150202"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20230420135520 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20230420135520"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20230817141244 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20230817141244"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20231103101649 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20231103101649"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20231108164138 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20231108164138"] 10:24:49 WARNING   [app] Migration App\Migrations\Version20231117113210 was executed but did not result in any SQL statements. ["version" => "App\Migrations\Version20231117113210"]   [] []
[2023-12-30 10:24:49] upgrade.INFO: Running step: finalize-clear-symfony-cache [] []
[2023-12-30 10:24:49] upgrade.INFO: step: finalize-clear-symfony-cache | status: done [] []
[2023-12-30 10:24:49] upgrade.INFO: step: finalize-clear-symfony-cache | messages: [] []
[2023-12-30 10:24:49] upgrade.INFO: Successfully cleared cache [] []
[2023-12-30 10:24:49] upgrade.INFO: step: finalize-clear-symfony-cache | debug: no debug info [] []

The only log that is being written, when I try to login is the webserver error log: [Sat Dec 30 10:59:30.485937 2023] [proxy_fcgi:error] [pid 740377] [client 85.17.14.46:54734] AH01071: Got error 'PHP message: PHP Deprecated: Return type of Symfony\\Component\\HttpFoundation\\Session\\Attribute\\AttributeBag::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 134PHP message: PHP Deprecated: Return type of Symfony\\Component\\HttpFoundation\\Session\\Attribute\\AttributeBag::count() should either be compatible with Countable::count(): int, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Attribute/AttributeBag.php on line 144PHP message: PHP Deprecated: Return type of Symfony\\Component\\HttpFoundation\\Session\\Session::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 131PHP message: PHP Deprecated: Return type of Symfony\\Component\\HttpFoundation\\Session\\Session::count() should either be compatible with Countable::count(): int, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /var/www/domain/service.domain/vendor/symfony/http-foundation/Session/Session.php on line 141'

Possible Fix

Steps to Reproduce

Follow the upgrade: https://docs.suitecrm.com/8.x/admin/installation-guide/upgrading/#_2_2_run_the_upgrade_command
Set the permissions: https://docs.suitecrm.com/8.x/admin/installation-guide/downloading-installing/
Try to login

Context

Your Environment

SuiteCRM Version used: 8.4 to 8.5
Browser name and version (e.g. Chrome Version 51.0.2704.63 (64-bit)): Chrome / Firefox
Environment name and version (e.g. MySQL, PHP 7): PHP 8.1, 10.6.12-MariaDB
Operating System and version (e.g Ubuntu 16.04): Ubuntu Server - Ubuntu 22.04.3 LTS

robertmilowski commented 8 months ago

Seems that the migration script does not create a table cache_rebuild , when I added manually every thing is working

chris001 commented 8 months ago

That sounds like a bug, should be investigated.

johnM2401 commented 8 months ago

Hey guys!

Thanks for getting in touch, @BastianHammer !

I've given this a test using the latest 8.5.0 package from the SuiteCRM website, and it appears to be creating the 'cache_rebuild' table as expected. (I've upgraded from 8.4.0 -> 8.5.0)

Is this the package you've also used?

From your provided upgrade.log, it appears as though your upgrade has at least attempted to create this table.

Noted by the lines:

[2023-12-30 10:24:49] upgrade.INFO: /* Table : cache_rebuild */ /* MISSING TABLE: cache_rebuild */ CREATE TABLE cache_rebuild (`cache_key` varchar(255)  NULL ,`rebuild` bool  NULL  ) CHARACTER SET utf8 COLLATE utf8_general_ci  [] []
[2023-12-30 10:24:49] upgrade.INFO: database repaired [] []

Perhaps the table has failed to create, somehow?

Could you check your SuiteCRM.log, (at /public/legacy/suitecrm.log), and let us know if anything relevant / DB-related has been printed out here?

(It may also be worth checking your PHP error logs)

Thanks again!

andreazino commented 8 months ago

I've the same problem but on a fresh installation with error "You have been logged out because your session has expired."

salesagility / SuiteCRM-Core