"An evolution has not been applied properly." error after 3.5.4 upgrade

rubberduck

On our university server with mysql database I used the auto update feature from 3.5.3 to 3.5.4. Afterwards jatos fails to start, the loader log shows

"An evolution has not been applied properly. Please check the problem and resolve it manually before marking it as resolved."

I am a bit stumped what I am supposed to do now.

What may be related: we are using the unit files as proposed in the documentation. I was wondering if the "restart=on-failure" setting could possibly interfere with the update script (i.e. starting jatos prematurely during an upgrade)

A bit of application.log that may or may not be relevant:

2020-05-18 15:07:44,076 [ERROR] - p.a.d.e.DefaultEvolutionsApi - Error on rename of './jatos/#sql-8d8_49f6' to './jatos/User' (errno: 150) [ERROR:1025, SQLSTATE:HY000]

2020-05-18 15:07:44,375 [INFO] - o.h.j.i.u.LogHelper - HHH000204: Processing PersistenceUnitInfo [name: mysqlPersistenceUnit]

2020-05-18 15:07:44,428 [INFO] - o.h.Version - HHH000412: Hibernate Core {5.4.2.Final}

2020-05-18 15:07:44,569 [INFO] - o.h.a.c.Version - HCANN000001: Hibernate Commons Annotations {5.1.0.Final}

2020-05-18 15:07:44,756 [INFO] - o.h.d.Dialect - HHH000400: Using dialect: org.hibernate.dialect.MySQL57Dialect

2020-05-18 15:07:45,108 [INFO] - o.h.v.i.u.Version - HV000001: Hibernate Validator 6.0.16.Final

2020-05-18 15:07:45,756 [INFO] - o.h.e.t.j.p.i.JtaPlatformInitiator - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]

2020-05-18 15:07:46,104 [INFO] - g.c.Common - Path to study assets directory is /XXXXXXXXXXXXXX/jatos/study_assets_root

2020-05-18 15:07:46,105 [INFO] - g.c.Common - Path to study logs directory is XXXXXXXXXXXXXXX/jatos/study_logs

2020-05-18 15:07:46,105 [INFO] - g.c.Common - Path to uploads directory is XXXXXXXXXXXXX/jatos/result_uploads

2020-05-18 15:07:46,394 [INFO] - g.OnStartStop - JATOS started

2020-05-18 15:07:46,602 [WARN] - o.h.e.j.s.SqlExceptionHelper - SQL Error: 1054, SQLState: 42S22

2020-05-18 15:07:46,602 [ERROR] - o.h.e.j.s.SqlExceptionHelper - Unknown column 'user0_.username' in 'field list'

2020-05-18 15:07:46,603 [INFO] - o.h.e.i.DefaultLoadEventListener - HHH000327: Error performing load command : org.hibernate.exception.SQLGrammarException: could not extract ResultSet

kri

Hi rubberduck,

There is one line in your log that worries me:

2020-05-18 15:07:44,076 [ERROR] - p.a.d.e.DefaultEvolutionsApi - Error on rename of './jatos/#sql-8d8_49f6' to './jatos/User' (errno: 150) [ERROR:1025, SQLSTATE:HY000]

All other errors are just a following of this one. It means that an automatic SQL schema update of your database (called evolution) did not go as planed. That's usually not a good sign. May I ask a couple of questions to narrow down the problem:

• Do you use the embedded H2 or an external MySQL database?
• If MySQL: Which version do you have?
• If MySQL: What is the 'db.default.url' in your DB config (usually in conf/production.conf but can be just a start parameter of loader.sh)?
• If MySQL: What access rights did you give to JATOS?
• If MySQL: Did you change anything in JATOS database manually, e.g. deleted a user by hand or deleted a table?

Best,

Kristian

rubberduck

Hi Kristian,

Thanks for the reply (and Jatos of course :-) )

We are running it on rhel7. I have mariadb 5.5.65 installed, for now on the same machine, so

db.default.url="jdbc:mysql://localhost/jatos?characterEncoding=UTF-8&useSSL=false&useJDBCCompliantTimezoneShift=true&useLegacyDatetimeCode=false&serverTimezone=UTC"

| GRANT USAGE ON *.* TO 'jatosuser'@'localhost' IDENTIFIED BY PASSWORD 'XXXXXXXXXXXXXXXXXXXXXX' |

| GRANT ALL PRIVILEGES ON `jatos`.* TO 'jatosuser'@'localhost'                                                    |

And I did not change anything in the database manually.

Regards,

Roelof

<edit> perhaps also of interest: this server started on 3.5.3, so this was the first update to it.

kri

Just to be sure: I tried out an update from 3.5.3 to 3.5.4 on my local JATOS with MySQL 5.7.30 and it worked.

rubberduck

ok,

Tomorrow I will deploy a clean virtual 3.5.3 server (everything is puppetised here) and see if that upgrades well. If it does not, I can try the same deployment but with mysql 5.7.30 to see if there is any difference.

Thankfully this was a testserver, so no data lost (and I have backups anyways).

Maybe I have run afoul of some arcane mariadb bug. Would not be the first time.

rubberduck

Ha, look here... https://mariadb.com/kb/en/mariadb-vs-mysql-compatibility/#incompatibilities-between-mariadb-55-and-mysql-55

I think the stock mariadb version in rhel (5.5.x) may have some compatibility issues with mysql 5.5. So I should either go to a mariadb 10.4 or use a mysql 5.7. or 8.0 Since both are available in redhat software channels I will simply switch to mysql 5.7 and call it a day.

kri

Hi Roelof,

I've never tried JATOS with MariaDB. They say MariaDB is an 'drop-in replacement' for MySQL but on the other side I can see some incompatibilities to MySQL on their page: https://mariadb.com/kb/en/incompatibilities-and-feature-differences-between-mariadb-103-and-mysql-57/.

And I found this on https://mariadb.com/kb/en/mariadb-vs-mysql-compatibility/:

MariaDB 10.2, MariaDB 10.3, and MariaDB 10.4 function as limited drop-in replacements for MySQL 5.7, as far as InnoDB is concerned. However, the implementation differences continue to grow in each new MariaDB version.

It sounds like if you want to try MariaDB (not that I'd recommend this) you should use version 10.2 to 10.4 and not version 5.5.65 like you have. But I'd suggest you give MySQL a try.

Best,

Kristian