Critical error after upgrading from 1.1 to 1.2

[timoschwarzer]

Describe the bug
After upgrading Kimai2 1.1 to 1.2 I'm getting a 500 on every page after login. I cleared the cache. Currently investigating the cause...

To Reproduce
Steps to reproduce the behavior:

1. Login to Kimai2
2. The dashboard throws a 500

Logfile

request.CRITICAL: Uncaught PHP Exception TypeError: "Argument 1 passed to App\Repository\Query\CustomerFormTypeQuery::setUser() must be an instance of App\Entity\User, null given, called in
/app/src/Form/Toolbar/AbstractToolbarForm.php on line 84"
at /app/src/Repository/Query/CustomerFormTypeQuery.php line 66 {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\FatalThrowableError(code: 0): Argument 1 passed to App\\Repository\\Query\\CustomerFormTypeQuery::setUser() must be an instance of App\\Entity\\User, null given, called in
/app/src/Form/Toolbar/AbstractToolbarForm.php on line 84
at /app/src/Repository/Query/CustomerFormTypeQuery.php:66)"} []

Additional context
Add any other context about the problem here.

• Kimai version 1.2
• PHP version 7.3.8

[j0hannesr0th]

have you run this command?

bin/console doctrine:migrations:migrate

[timoschwarzer]

@hmr-it-jr yes.
Latest migration is

20190813162649 - Changing column sizes to prevent index length errors

[kevinpapst]

https://demo-stable.kimai.org/ looks good
Composer update was successful? Do a rm -rf var/cache/* and re-login after a warmup.

[j0hannesr0th]

I've updated my Kimai 1.1 to 1.2 20 minutes ago and everything was ok.
I've followed the exact steps like in the documentation. Maybe you forgot to run composer?

https://www.kimai.org/documentation/updates.html

[timoschwarzer]

/app $ composer i --no-dev -o
Loading composer repositories with package information
Installing dependencies from lock file
Nothing to install or update
Generating optimized autoload files
ocramius/package-versions:  Generating version class...
ocramius/package-versions: ...done generating version class
Executing script cache:clear [OK]
Executing script assets:install [OK]

/app $ rm -rf var/cache/
/app $ bin/console cache:warmup

Notice: Found ambiguous configuration. Please remove "kimai.timesheet.duration_only" and set "kimai.timesheet.mode" instead. in /app/src/DependencyInjection/AppExtension.php on line 39

 // Warming up the cache for the prod environment with debug false                                                      

                                                                                                                        
 [OK] Cache for the "prod" environment (debug=false) was successfully warmed.                                           
                                                                                                                        

/app $

I need to fix the config, but this can't be the cause, can it? The repository is on commit 94f8159, which is 1.2. Unfortunately I still cannot visit any page without that error being thrown.

[kevinpapst]

Composer is up to date? Some users had troubles with an outdated composer.
Please remove the local.yaml and refresh the cache, just to check if that is the cause.

[kevinpapst]

Oh and git status is clean?

[j0hannesr0th]

When I've run

composer install --no-dev --optimize-autoloader

composer installed/updated about 40 packages and removed 8.

[timoschwarzer]

@hmr-it-jr

composer installed/updated about 40 packages and removed 8.

It did (un)install/upgrade some packages when I did it the first time.

@kevinpapst

Please remove the local.yaml and refresh the cache, just to check if that is the cause

Tried that without success.

Oh and git status is clean?

git status reports a clean working tree and git fsck has no errors.

Composer is up to date? Some users had troubles with an outdated composer.

I'm on 1.8.6. Will update to 1.9 and see if that fixes it...

[timoschwarzer]

... using Composer 1.9 didn't install/upgrade/remove anything.

[timoschwarzer]

/admin/user is one of the few pages that work.

[kevinpapst]

Yeah, because there is no customer choice in the filter toolbar. But it just doesn't make any sense. The dashboard should work as well, same with tags, system settings, about...
The error "more or less" says that you there is no logged in user.

This code injects the current user into each form:
https://github.com/kevinpapst/kimai2/blob/master/src/Form/Extension/UserExtension.php#L43
and this fetches the current user:
https://github.com/kevinpapst/kimai2/blob/master/src/Security/CurrentUser.php

I guess you can only debug the code to see what is going on. Or you paste some more logs...

[timoschwarzer]

I think I found the issue:

mysql> show tables;
+--------------------------+
| Tables_in_kimai          |
+--------------------------+
| kimai2_activities        |
| kimai2_activities_meta   |
| kimai2_configuration     |
| kimai2_customers         |
| kimai2_customers_meta    |
| kimai2_invoice_templates |
| kimai2_projects          |
| kimai2_projects_meta     |
| kimai2_tags              |
| kimai2_timesheet         |
| kimai2_timesheet_meta    |
| kimai2_timesheet_tags    |
| kimai2_user_preferences  |
| kimai2_users             |
| migration_versions       |
+--------------------------+
15 rows in set (0.00 sec)

mysql> select * from migration_versions;
+----------------+---------------------+
| version        | executed_at         |
+----------------+---------------------+
| 20180701120000 | 2019-04-24 23:25:20 |
| 20180715160326 | 2019-04-24 23:25:20 |
| 20180730044139 | 2019-04-24 23:25:20 |
| 20180805183527 | 2019-04-24 23:25:20 |
| 20180903202256 | 2019-04-24 23:25:20 |
| 20180905190737 | 2019-04-24 23:25:20 |
| 20180924111853 | 2019-04-24 23:25:20 |
| 20181031220003 | 2019-04-24 23:25:20 |
| 20190124004014 | 2019-04-24 23:25:20 |
| 20190201150324 | 2019-04-24 23:25:20 |
| 20190219200020 | 2019-04-24 23:25:20 |
| 20190305152308 | 2019-04-24 23:25:20 |
| 20190321181243 | 2019-04-24 23:25:20 |
| 20190502161758 | 2019-07-03 17:15:29 |
| 20190510205245 | 2019-07-03 17:15:30 |
| 20190605171157 | 2019-07-03 17:15:30 |
| 20190617100845 | 2019-07-03 17:15:31 |
| 20190706224211 | 2019-08-29 19:35:21 |
| 20190706224219 | 2019-08-29 19:35:21 |
| 20190729162655 | 2019-08-29 19:35:21 |
| 20190730123324 | 2019-08-29 19:35:21 |
| 20190813162649 | 2019-08-29 19:35:21 |
+----------------+---------------------+
22 rows in set (0.00 sec)

For some reason, the migrations haven't been executed but marked as done. Very strange.

[kevinpapst]

Huh? That should lead to other errors.
Well then, delete the rows from the migration_versions table and re-execute the migrations.

[timoschwarzer]

Okay, I did a quick an dirty bin/console doctr1ne:schema:update --force (Check the SQL manually before you execute this! bin/console doctrine:schema:update --dump-sql. You may lose data!) to force the database schema to match and now the schema seems to be up to date with the migrations. The app works again at least. I can't tell you how the migrations weren't executed properly though... I cannot remember any errors running bin/console doctrine:migrations:migrate...

I will keep an eye on this... Thank you very much for you fast responses and help @kevinpapst and @hmr-it-jr! :)

[kevinpapst]

Glad it works now!

But to anyone reading this thread and with less knowledge about Symfony & Doctrine:

DO NOT EXECUTE "schema:update --force" - THAT IS VERY UNSAFE AND CAN LEAD TO DATA LOSS (depending on the outstanding migrations).

[timoschwarzer]

Good warning! Updated my comment so no one can just paste the command.

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs. If you use Kimai on a daily basis, please consider donating to support further development of Kimai.