Upgrade from 4.0.3 to 4.1.0 hangs on "Updating database..."

[theofficialgman]

Shlink version

4.1.0

PHP version

8.3.11

How do you serve Shlink

Self-hosted nginx

Database engine

MySQL

Database version

8.0.39

Current behavior

attempting to perform a ./vendor/bin/shlink-installer update on my existing instance of shlink hangs on "Updating database..."

Expected behavior

updating does not hang

Minimum steps to reproduce

install shlink 4.0.3 and setup
log clicks (my database just passed 5,000,000 with a few hundred shorturls)
attempt update to 4.1.0

[theofficialgman]

running with -vvv produces the following output

Updating database... [Running "/usr/bin/php8.3 bin/cli db:migrate"]   RUN  '/usr/bin/php8.3' 'bin/cli' 'db:migrate'
  OUT  Migrating database...
  OUT  
  ERR    RUN  '/usr/bin/php8.3' 'vendor/doctrine/migrations/bin/doctrine-migrations.php' 'migrations:migrate' '--no-interaction'
  ERR    OUT  
  ERR    OUT   [WARNING] You have 16 previously executed migrations in the database that are  
  ERR    OUT             not registered migrations.                                           
  ERR    OUT  
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20160819142757)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20160820191203)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20171021093246)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20171022064541)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180801183328)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180913205455)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180915110857)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181020060559)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181020065148)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181110175521)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20190824075137)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20190930165521)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20191001201532)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20191020074522)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20200110182849)
  ERR    OUT   >> 2022-05-09 06:10:09 (ShlinkMigrations\Version20210118153932)
  ERR    OUT  

[theofficialgman]

migrating from my 4.0.3 to another fresh 4.0.3 succeeds (as expected) with the following output

/var/www/shlink4.0.3_php8.3_dist# ./vendor/bin/shlink-installer update -vvv
 Welcome to Shlink!!
 This tool will guide you through the installation process.

 Do you want to import configuration from previous installation? (You will still be asked for any new config option that did not exist in previous shlink versions) (yes/no) [yes]:
 > y

 Previous shlink installation path from which to import config:
 > /var/www/shlink

 Custom configuration properly generated!

Updating database... [Running "/usr/bin/php8.3 bin/cli db:migrate"]   RUN  '/usr/bin/php8.3' 'bin/cli' 'db:migrate'
  OUT  Migrating database...
  OUT  
  ERR    RUN  '/usr/bin/php8.3' 'vendor/doctrine/migrations/bin/doctrine-migrations.php' 'migrations:migrate' '--no-interaction'
  ERR    OUT  
  ERR    OUT   [WARNING] You have 17 previously executed migrations in the database that are  
  ERR    OUT             not registered migrations.                                           
  ERR    OUT  
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20160819142757)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20160820191203)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20171021093246)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20171022064541)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180801183328)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180913205455)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20180915110857)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181020060559)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181020065148)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20181110175521)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20190824075137)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20190930165521)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20191001201532)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20191020074522)
  ERR    OUT   >> 2022-05-09 06:10:08 (ShlinkMigrations\Version20200110182849)
  ERR    OUT   >> 2022-05-09 06:10:09 (ShlinkMigrations\Version20210118153932)
  ERR    OUT   >> 2024-09-03 19:08:27 (ShlinkMigrations\Version20240306132518)
  ERR    OUT  
  ERR    OUT   [OK] Successfully migrated to version: ShlinkMigrations\Version20240227080629  
  ERR    OUT  
  ERR    OUT  
  ERR    OUT  
  ERR    RES  Command ran successfully
  ERR  
  OUT  
  OUT   [OK] Database properly migrated!                                               
  OUT  
  OUT  
  RES  Command ran successfully
 Success!
Generating proxies... [Running "/usr/bin/php8.3 bin/doctrine orm:generate-proxies"]   RUN  '/usr/bin/php8.3' 'bin/doctrine' 'orm:generate-proxies'
  ERR   Processing entity "Shlinkio\Shlink\Core\Visit\Entity\Visit"
  ERR   Processing entity "Shlinkio\Shlink\Core\ShortUrl\Entity\ShortUrl"
  ERR   Processing entity "Shlinkio\Shlink\Core\RedirectRule\Entity\ShortUrlRedirectRule"
  ERR   Processing entity "Shlinkio\Shlink\Core\RedirectRule\Entity\RedirectCondition"
  ERR   Processing entity "Shlinkio\Shlink\Core\Tag\Entity\Tag"
  ERR   Processing entity "Shlinkio\Shlink\Core\Visit\Entity\VisitLocation"
  ERR   Processing entity "Shlinkio\Shlink\Core\Domain\Entity\Domain"
  ERR   Processing entity "Shlinkio\Shlink\Rest\Entity\ApiKey"
  ERR   Processing entity "Shlinkio\Shlink\Rest\Entity\ApiKeyRole"
  ERR  
  ERR   Proxy classes generated to "/var/www/shlink4.0.3_php8.3_dist/data/proxies"
  ERR  
  RES  Command ran successfully
 Success!
Clearing entities cache... [Running "/usr/bin/php8.3 bin/doctrine orm:clear-cache:metadata"]   RUN  '/usr/bin/php8.3' 'bin/doctrine' 'orm:clear-cache:metadata'
  ERR  
  ERR   // Clearing all Metadata cache entries                                         
  ERR  
  ERR   [OK] Successfully deleted cache entries.                                       
  ERR  
  ERR  
  RES  Command ran successfully
 Success!
Downloading GeoLite2 db file... [Running "/usr/bin/php8.3 bin/cli visit:download-db"]   RUN  '/usr/bin/php8.3' 'bin/cli' 'visit:download-db'
  OUT  
  OUT   [INFO] GeoLite2 db file is up to date.                                         
  OUT  
  OUT  
  RES  Command ran successfully
 Success!

                                                                                                                        
 [OK] Installation complete!                                                                                            
                                                                                                                        

[acelaya]

It very likely feels like it's hanging due to this migration https://github.com/shlinkio/shlink/blob/develop/module%2FCore%2Fmigrations%2FVersion20240318084804.php

With 5M visits, that's going to take a while to finish.

[acelaya]

That timeout is defined here https://github.com/shlinkio/shlink-installer/blob/c1afdd68110fcf2b66c78b24c258c83e051de2ef/config/config.php#L257

In a Shlink dist, you should find that in vendor/bin/shlinkio/shlink-installer/config/config.php.

10 minutes have worked well so far, but I'm wondering if there should be a way to override that. Not sure how though.

[acelaya]

Actually, you'll have to increase this as well (there's a chain of processes there, each with its own timeout): https://github.com/shlinkio/shlink/blob/9afc7876c4d5ee9c8f734befe514cd532080fc55/module/CLI/src/Util/ProcessRunner.php#L27

In there, where it says timeout: LockedCommandConfig::DEFAULT_TTL, you'll have to set timeout: some_big_number.

[theofficialgman]

That probably would work however now migrations complete immediately. I was under the impression that migrations would only write to the database on completion but this must not be the case. I believe I need to delete the "dirty" migration now in order to start it over again.

[theofficialgman]

I assume that I can simply delete the orphan_visits_counts and short_url_visits_counts tables from the database and it will regenerate those on upgrade.

edit: Looks like I also need to delete the appropriate rows from the migrations table so they run again.

[theofficialgman]

After performing the above database cleanup and increasing the timeouts the database migration completed successfully in 30 minutes.