[OJS] HTTP 500 error logging in after upgrading to 3.3.0.7

Description of issue or problem I’m having:
HTTP 500 error occasionally when logging in to OJS after upgrading from 3.1.1.2 to 3.3.0.7

Steps I took leading up to the issue:
Upgrading to 3.3.0.7, I did have some issues with not only character encoding (database was latin1), but differing database engines across tables. I had to manually set some tables to MyISAM to get the upgrade to complete without foreign key errors. Everything except for this so far seems good post-all these issues though.

What I tried to resolve the issue:
Nothing yet, if you refresh the page it logs in fine.

Application Version - e.g., OJS 3.1.2:
OJS 3.3.0.7

Additional information, such as screenshots and error log messages if applicable:
From the Apache error log when the 500 error happens:
[php7:error] [pid 23983:tid 139654652159744] [client 128.226.57.168:54311] PHP Fatal error: Uncaught PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry ‘1’ for key ‘user_settings_user_id’ in /var/www/html/lib/pkp/lib/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:115

Hi @russellj,

It looks the key user_settings_user_id in the user_settings table may have gotten set up as a unique key, which shouldn’t be the case in the settings tables. Could you run SHOW CREATE TABLE user_settings in your database and share the output for that?

Thanks.

Regards,

Erik
PKP Team

@ewhanson Thank you for considering this issue, the output is as follows:

mysql> SHOW CREATE TABLE user_settings\G
*************************** 1. row ***************************
Table: user_settings
Create Table: CREATE TABLE user_settings (
user_id bigint(20) NOT NULL,
locale varchar(14) NOT NULL DEFAULT ‘’,
setting_name varchar(255) NOT NULL,
assoc_type bigint(20) DEFAULT ‘0’,
assoc_id bigint(20) DEFAULT ‘0’,
setting_value text,
setting_type varchar(6) NOT NULL,
UNIQUE KEY user_settings_pkey (user_id,locale,setting_name,assoc_type,assoc_id),
KEY user_settings_user_id (user_id),
KEY user_settings_locale_setting_name_index (setting_name,locale)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

Hi @russellj,

Thanks for sharing the output. It doesn’t look like this is what’s causing the issue.

Another possibility is that the users table contains a user_id that appears more than once. From your error message above it looks like the user_id was 1, but it’s probably worthwhile to see if there are any other duplicate user_ids in the users table.

Could you check to see if this is the case?

Regards,

Erik
PKP Team

@ewhanson Doesn’t look like there’s any duplicates, if my queries are correct:

mysql> select * from users group by user_id having count(*) > 1;
Empty set (0.00 sec)

mysql> select user_id from users;
983 rows in set (0.00 sec)
mysql> select distinct user_id from users;
983 rows in set (0.01 sec)

Just scanning the Apache log, I would make an educated guess that everyone gets this the first time they try to log in for the day. Do you think there’s any chance it has anything to do with differing database engines? I did struggle with that during the upgrade. I kept having to reload the database to pre-upgrade, and re-upgrade it until I hit all the tables that had an issue being different (MyISAM vs InnoDB).

Hi @russellj,

Thanks for sharing that. It is strange that it seems to be happening to others but only once in a while. This kind of reaches my limit on database knowledge, but others on here will probably know more.

Regards,

Erik
PKP Team

Hi @russellj,

I checked with a colleague who offered the following suggestions for further narrowing down the issue:

I don’t know if this is feasible at all, but they could try duplicating that installation on a private server, turning on the debug setting in the config file and then getting OJS queries dumped at them. They’d get the last query right before it all failed, perhaps.

MySQL also has a global general_log variable that you can set to On, which will log everything. It’d be incredibly verbose but it may turn something up too.

Hope that helps!

Regards,

Erik
PKP Team

Hi @russellj,

Another out there place to look in case the rest doesn’t turn up anything:

If it’s only happening once to everyone, I wonder if it’s a database update on the users table to update the “last login” field or maybe the sessions table, which also has a user_id column. I know it was complaining about the user_settings table, which sounds like the queries are failing when trying to build the user object itself.

Regards,

Erik
PKP Team

@ewhanson I am looking at increasing the log levels now. Thanks for the suggestions more to follow…

So I have the OJS instance cloned… but so far am not able to recreate the issue on the test server. That’s telling in itself as it was easy to recreate on the main server. Both are running the same Linux distro and version. The MySQL version differs slightly but is close and both are within requirements, PHP is the same version. Any other ideas to compare in the server environment that might cause this?

Main server
PHP 7.4.24 (cli) (built: Sep 21 2021 11:23:11) ( NTS )
mysql Ver 14.14 Distrib 5.5.0-m2
Test server
PHP 7.4.24 (cli) (built: Sep 21 2021 11:23:11) ( NTS )
mysql Ver 14.14 Distrib 5.6.30