Deployer: deploy:vendors step is very slow (take up to 2 mins)

[jolipixel]

| Q | A
| ----------------- | ---
| Issue Type | Bug
| Deployer Version | N/A
| Local Machine OS | N/A
| Remote Machine OS | N/A

Description

If I type dep deploy, the step deploy:vendors is terribly slow. This step only can take up to 2 minutes.

However, if I only type dep deploy:vendors, it is very fast (2 s)

Steps to reproduced

dep deploy-vvv

Content of deploy.php

<?php
namespace Deployer;
require 'recipe/symfony.php';
require 'vendor/deployer/recipes/cachetool.php';

//------------------------------
// Configuration
//------------------------------
set('ssh_type', 'native');
set('ssh_multiplexing', true); 
set('repository', '***');
set('default_stage', '****-stage');
set('shared_files', ['app/config/parameters.yml.dist']);

add('shared_dirs', ['/web/uploads']);
add('writable_dirs', ['/web/uploads']);

//------------------------------
// Servers
//------------------------------

server('****-stage', '*.*.*.*')
    ->stage('stage')
    ->set('env', 'dev')
    ->set('composer_options', '{{composer_action}} --verbose --prefer-dist --no-progress --no-interaction --optimize-autoloader')
    ->set('clear_paths', ['web/config.php'])
    ->set('deploy_path', '/home/****/stage')
    ->set('cachetool', '/var/run/php/php7.1-fpm.sock')
    ->user('***')
    ->forwardAgent()
    ->set('branch', 'master');

server('****', '*.*.*.*')
    ->stage('prod')
    ->set('deploy_path', '/home/****/prod')
    ->user('***')
    ->forwardAgent()
    ->set('branch', 'master');

//------------------------------
// Tasks
//------------------------------

// If deploy fails automatically unlock.
after('deploy:failed', 'deploy:unlock');

// Migrate database before symlink new release.
before('deploy:symlink', 'database:migrate');

// Clear opcache
after('deploy:symlink', 'cachetool:clear:opcache');

task('upload-stage-files', function () {
    $deployPath = get('deploy_path');
    upload("web/uploads/", "/home/****/stage/shared/web/uploads/");
}); 

Output log

*
$ dep deploy -vvv
➤ Executing task deploy:prepare
[project-stage] > echo $0
SSH multiplexing initialization
[project-stage] < bash
[project-stage] > if [ ! -d /home/project/stage ]; then mkdir -p /home/project/stage; fi
[project-stage] > if [ ! -L /home/project/stage/current ] && [ -d /home/project/stage/current ]; then echo true; fi
[project-stage] > cd /home/project/stage && if [ ! -d .dep ]; then mkdir .dep; fi
[project-stage] > cd /home/project/stage && if [ ! -d releases ]; then mkdir releases; fi
[project-stage] > cd /home/project/stage && if [ ! -d shared ]; then mkdir shared; fi
• done on [project-stage]
✔ Ok [1s 669ms]
➤ Executing task deploy:lock
[project-stage] > if [ -f /home/project/stage/.dep/deploy.lock ]; then echo 'true'; fi
[project-stage] > touch /home/project/stage/.dep/deploy.lock
• done on [project-stage]
✔ Ok [323ms]
➤ Executing task deploy:release
[project-stage] > cd /home/project/stage && (if [ -h release ]; then echo 'true'; fi)
[project-stage] > cd /home/project/stage && ([ -d releases ] && [ "$(ls -A releases)" ] && echo "true" || echo "false")
[project-stage] < true
[project-stage] > cd /home/project/stage && (cd releases && ls -t -1 -d /)
[project-stage] < 47/
[project-stage] < 46/
[project-stage] < 45/
[project-stage] < 44/
[project-stage] < 43/
[project-stage] > cd /home/project/stage && (if [ -f .dep/releases ]; then echo "true"; fi)
[project-stage] < true
[project-stage] > cd /home/project/stage && (tail -n 15 .dep/releases)
[project-stage] < 20170517034610,34
[project-stage] < 20170518103746,35
[project-stage] < 20170522094409,36
[project-stage] < 20170524005420,37
[project-stage] < 20170526150548,38
[project-stage] < 20170526151306,38
[project-stage] < 20170526151918,39
[project-stage] < 20170526160749,40
[project-stage] < 20170526173000,41
[project-stage] < 20170526174846,42
[project-stage] < 20170529093817,43
[project-stage] < 20170529100016,44
[project-stage] < 20170529150528,45
[project-stage] < 20170529151617,46
[project-stage] < 20170529152042,47
[project-stage] > cd /home/project/stage && (if [ -d /home/project/stage/releases/48 ]; then echo 'true'; fi)
[project-stage] > cd /home/project/stage && (date +"%Y%m%d%H%M%S")
[project-stage] < 20170529153205
[project-stage] > cd /home/project/stage && (echo '20170529153205,48' >> .dep/releases)
[project-stage] > cd /home/project/stage && (mkdir /home/project/stage/releases/48)
[project-stage] > cd /home/project/stage && (if [[ "$(man ln)" =~ "--relative" ]]; then echo "true"; fi)
[project-stage] < true
[project-stage] > cd /home/project/stage && (ln -nfs --relative /home/project/stage/releases/48 /home/project/stage/release)
• done on [project-stage]
✔ Ok [1s 932ms]
➤ Executing task deploy:update_code
[project-stage] > which git
[project-stage] < /usr/bin/git
[project-stage] > /usr/bin/git version
[project-stage] < git version 2.1.4
[project-stage] > if [ -h /home/project/stage/release ]; then echo 'true'; fi
[project-stage] < true
[project-stage] > readlink /home/project/stage/release
[project-stage] < releases/48
[project-stage] > /usr/bin/git clone -b master --depth 1 --recursive -q [email protected]:project/project.git /home/project/stage/releases/48 2>&1
• done on [project-stage]
✔ Ok [3s 308ms]
➤ Executing task deploy:clear_paths
[project-stage] > rm -rf /home/project/stage/releases/48/web/config.php
• done on [project-stage]
✔ Ok [165ms]
➤ Executing task deploy:create_cache_dir
[project-stage] > if [ -d "/home/project/stage/releases/48/app/cache" ]; then rm -rf /home/project/stage/releases/48/app/cache; fi
[project-stage] > mkdir -p /home/project/stage/releases/48/app/cache
[project-stage] > chmod -R g+w /home/project/stage/releases/48/app/cache
• done on [project-stage]
✔ Ok [533ms]
➤ Executing task deploy:shared
[project-stage] > if [ -d /home/project/stage/shared/app/logs ]; then echo 'true'; fi
[project-stage] < true
[project-stage] > rm -rf /home/project/stage/releases/48/app/logs
[project-stage] > mkdir -p dirname /home/project/stage/releases/48/app/logs
[project-stage] > ln -nfs --relative /home/project/stage/shared/app/logs /home/project/stage/releases/48/app/logs
[project-stage] > if [ -d /home/project/stage/shared//web/uploads ]; then echo 'true'; fi
[project-stage] < true
[project-stage] > rm -rf /home/project/stage/releases/48//web/uploads
[project-stage] > mkdir -p dirname /home/project/stage/releases/48//web/uploads
[project-stage] > ln -nfs --relative /home/project/stage/shared//web/uploads /home/project/stage/releases/48//web/uploads
[project-stage] > if [ -f $(echo /home/project/stage/releases/48/app/config/parameters.yml.dist) ]; then rm -rf /home/project/stage/releases/48/app/config/parameters.yml.dist; fi
[project-stage] > if [ ! -d $(echo /home/project/stage/releases/48/app/config) ]; then mkdir -p /home/project/stage/releases/48/app/config;fi
[project-stage] > mkdir -p /home/project/stage/shared/app/config
[project-stage] > touch /home/project/stage/shared/app/config/parameters.yml.dist
[project-stage] > ln -nfs --relative /home/project/stage/shared/app/config/parameters.yml.dist /home/project/stage/releases/48/app/config/parameters.yml.dist
• done on [project-stage]
✔ Ok [2s 287ms]
➤ Executing task deploy:assets
[project-stage] > find /home/project/stage/releases/48/web/css /home/project/stage/releases/48/web/images /home/project/stage/releases/48/web/js -exec touch -t 201705290132.12 {} ';' &> /dev/null || true
• done on [project-stage]
✔ Ok [215ms]
➤ Executing task deploy:vendors
[project-stage] > if hash composer 2>/dev/null; then echo 'true'; fi
[project-stage] < true
[project-stage] > which composer
[project-stage] < /usr/local/bin/composer
[project-stage] > which php
[project-stage] < /usr/bin/php
[project-stage] > cd /home/project/stage/releases/48 && SYMFONY_ENV=dev /usr/bin/php /usr/local/bin/composer install --verbose --prefer-dist --no-progress --no-interaction --optimize-autoloader
[project-stage] < ocramius/package-versions: Generating version class...
[project-stage] < ocramius/package-versions: ...done generating version class
[project-stage] < Creating the "app/config/parameters.yml" file
[project-stage] <
[project-stage] < // Clearing the cache for the dev environment with debug true
[project-stage] <
[project-stage] < [OK] Cache for the "dev" environment (debug=true) was successfully cleared.
[project-stage] <
[project-stage] <
[project-stage] < Trying to install assets as relative symbolic links.
[project-stage] <
[project-stage] < --- --------------------- ------------------
[project-stage] < Bundle Method / Error
[project-stage] < --- --------------------- ------------------
[project-stage] < ✔ FrameworkBundle relative symlink
[project-stage] < ✔ MopaBootstrapBundle relative symlink
[project-stage] < --- --------------------- ------------------
[project-stage] <
[project-stage] < [OK] All assets were successfully installed.
• done on [project-stage]
✔ Ok [112s 930ms]
➤ Executing task deploy:assets:install
[project-stage] > SYMFONY_ENV=dev /usr/bin/php /home/project/stage/releases/48/app/console assets:install --no-interaction --env=dev /home/project/stage/releases/48/web
[project-stage] <
[project-stage] < Installing assets as hard copies.
[project-stage] <
[project-stage] < --- --------------------- ----------------
[project-stage] < Bundle Method / Error
[project-stage] < --- --------------------- ----------------
[project-stage] < ✔ FrameworkBundle copy
[project-stage] < ✔ MopaBootstrapBundle copy
[project-stage] < --- --------------------- ----------------
[project-stage] <
[project-stage] < ! [NOTE] Some assets were installed via copy. If you make changes to these assets you have to run this command again.
[project-stage] <
[project-stage] < [OK] All assets were successfully installed.
• done on [project-stage]
✔ Ok [407ms]
➤ Executing task deploy:assetic:dump
• done on [project-stage]
✔ Ok [0ms]
➤ Executing task deploy:cache:warmup
[project-stage] > SYMFONY_ENV=dev /usr/bin/php /home/project/stage/releases/48/app/console cache:warmup --no-interaction --env=dev
[project-stage] <
[project-stage] < // Warming up the cache for the dev environment with debug true
[project-stage] <
[project-stage] < [OK] Cache for the "dev" environment (debug=true) was successfully warmed.
• done on [project-stage]
✔ Ok [3s 97ms]
➤ Executing task deploy:writable
[project-stage] > ps axo user,comm | grep -E '[a]pache|[h]ttpd|[_]www|[w]ww-data|[n]ginx' | grep -v root | head -1 | cut -d\ -f1
[project-stage] < www-data
[project-stage] > cd /home/project/stage/releases/48 && (mkdir -p app/cache app/logs /web/uploads)
[project-stage] > cd /home/project/stage/releases/48 && (chmod 2>&1; true)
[project-stage] < chmod: missing operand
[project-stage] < Try 'chmod --help' for more information.
[project-stage] > cd /home/project/stage/releases/48 && (if hash setfacl 2>/dev/null; then echo 'true'; fi)
[project-stage] < true
[project-stage] > cd /home/project/stage/releases/48 && (getfacl -p app/cache | grep "^user:www-data:.w" | wc -l)
[project-stage] < 0
[project-stage] > cd /home/project/stage/releases/48 && (setfacl -RL -m u:"www-data":rwX -m u:whoami:rwX app/cache)
[project-stage] > cd /home/project/stage/releases/48 && (setfacl -dRL -m u:"www-data":rwX -m u:whoami:rwX app/cache)
[project-stage] > cd /home/project/stage/releases/48 && (getfacl -p app/logs | grep "^user:www-data:.w" | wc -l)
[project-stage] < 1
[project-stage] > cd /home/project/stage/releases/48 && (getfacl -p /web/uploads | grep "^user:www-data:.w" | wc -l)
[project-stage] < 1
• done on [project-stage]
✔ Ok [1s 500ms]
➤ Executing task database:migrate
[project-stage] > SYMFONY_ENV=dev /usr/bin/php /home/project/stage/releases/48/app/console doctrine:migrations:migrate --no-interaction --env=dev --allow-no-migration
[project-stage] <
[project-stage] < Application Migrations
[project-stage] <
[project-stage] <
[project-stage] < No migrations to execute.
• done on [project-stage]
✔ Ok [549ms]
➤ Executing task deploy:symlink
[project-stage] > if [[ "$(man mv)" =~ "--no-target-directory" ]]; then echo "true"; fi
[project-stage] < true
[project-stage] > mv -T /home/project/stage/release /home/project/stage/current
• done on [project-stage]
✔ Ok [356ms]
➤ Executing task cachetool:clear:opcache
[project-stage] > cd /home/project/stage/releases/48 && (if [ -e /home/project/stage/releases/48/cachetool.phar ]; then echo 'true'; fi)
[project-stage] > cd /home/project/stage/releases/48 && (curl -sO https://gordalina.github.io/cachetool/downloads/cachetool.phar)
[project-stage] > cd /home/project/stage/releases/48 && (/usr/bin/php cachetool.phar opcache:reset --fcgi=/var/run/php/php7.1-fpm.sock)
• done on [project-stage]
✔ Ok [1s 363ms]
➤ Executing task deploy:unlock
[project-stage] > rm -f /home/project/stage/.dep/deploy.lock
• done on [project-stage]
✔ Ok [160ms]
➤ Executing task cleanup
[project-stage] > rm -rf /home/project/stage/releases/43
[project-stage] > cd /home/project/stage && if [ -e release ]; then rm release; fi
[project-stage] > cd /home/project/stage && if [ -h release ]; then rm release; fi
• done on [project-stage]
✔ Ok [1s 326ms]
➤ Executing task success
✔ Ok [0ms]
Successfully deployed!
*

[antonmedv]

It's because composer installing deps. When you run dep deploy:vendors all deps already installed, so nothing goes not.

Make sure you use latest composer installed and it's uses cache.

[jolipixel]

Hello,

It is the latest composer version.

I have done a composer clear-cache and retried a new time dep deploy-vvv : my ~/.composer/cache folder went from 0 to 64M.

I have tried one last time dep deploy-vvv:

➤ Executing task deploy:vendors
[project-stage] > if hash composer 2>/dev/null; then echo 'true'; fi
[project-stage] < true
[project-stage] > which composer
[project-stage] < /usr/local/bin/composer
[project-stage] > which php
[project-stage] < /usr/bin/php
[project-stage] > cd /home/project/stage/releases/54 && SYMFONY_ENV=dev /usr/bin/php /usr/local/bin/composer install --verbose --prefer-dist --no-progress --no-interaction --optimize-autoloader
    [project-stage] < ocramius/package-versions:  Generating version class...
[project-stage] < ocramius/package-versions: ...done generating version class
[project-stage] < Creating the "app/config/parameters.yml" file
[project-stage] <
[project-stage] <  // Clearing the cache for the dev environment with debug true
[project-stage] <
[project-stage] <  [OK] Cache for the "dev" environment (debug=true) was successfully cleared.
[project-stage] <
[project-stage] <
[project-stage] <  Trying to install assets as relative symbolic links.
[project-stage] <
[project-stage] <  --- --------------------- ------------------
[project-stage] <       Bundle                Method / Error
[project-stage] <  --- --------------------- ------------------
[project-stage] <   ✔   FrameworkBundle       relative symlink
[project-stage] <   ✔   MopaBootstrapBundle   relative symlink
[project-stage] <  --- --------------------- ------------------
[project-stage] <
[project-stage] <  [OK] All assets were successfully installed.
• done on [project-stage]
✔ Ok [113s 88ms]

This step took 113 seconds.

How can i make Composer uses its cache when called via Deployer ?

[snowiow]

Composer always uses it's cache. There isn't even an option to turn the composer cache off. See this discussion.

I have done a composer clear-cache and retried a new time dep deploy-vvv : my ~/.composer/cache folder went from 0 to 64M.

So composer is already caching right? You should try to deploy again with a filled cache and not clear the cache afterwards. This time composer should use your cached packages and not download them again. This should result in a faster deploy:vendor step.

[jolipixel]

The ~/.composer/cache folder is filled with data (64M). But on dep deploy, composer still spends 2 minutes on the deploy:vendor step.

I did the clear-cache command only to check if composer was caching on a dep deploy command. It is : the cache is created in ~/.composer/cache. But it seems it is not reading it on futures dep deploy.

[snowiow]

Are you sure that it's a problem of the package download of composer? Normally your log should contain something like this (this is taken from my local vm deploy):

[vagrant] > cd /var/www/html/project/releases/7 &&  /usr/bin/php /usr/bin/composer install --verbose --prefer-dist --no-progress --no-interaction --optimize-autoloader
[vagrant] < Loading composer repositories with package information
[vagrant] < Installing dependencies (including require-dev) from lock file
[vagrant] < Dependency resolution completed in 0.001 seconds
[vagrant] < Analyzed 190 packages to resolve dependencies
[vagrant] < Analyzed 482 rules to resolve dependencies
[vagrant] <   - Installing skyzyx/mimetypes (1.1.1)
[vagrant] <     Loading from cache
[vagrant] <     Extracting archive
[vagrant] <   - Installing apfelbox/php-file-download (v2.1)
[vagrant] <     Loading from cache
[vagrant] <     Extracting archive

As you can see, it tells you that it is using the cache for those two packages for example. If the package isn't cached, it would tell you something like download package. Your log on the other hand seems to not load a single package in the deploy:vendor step. So the problem for the delay has to lie somewhere else I think.

[antonmedv]

Also you can try something like this:

set('copy_dirs', ['vendor']);

[andrewtch]

Ow :) I just visited the issues with the same thought but actually there is a task about composer being slow ))

As for me, I have an offer - maybe we should check if composer.lock did not change since previous release (md5sum compare of {{current_path}}/composer.lock and {{deploy_path}}/composer.lock) if composer did not change?

Of course, we should have "composer_skip_unchanged" defaulting to false to avoid BC's.

[milosmiric]

@andrewtch I don't think that Deployer needs to worry about your composer install speed at all, it's there to execute commands, not have specific implementation optimizations.

[ryancastle]

Won't deploy:vendors typically do nothing when run in isolation, because it's run in an existing directory that already has a complete vendors? I think copy_dirs is the mitigation for a full deployment. But it will still be much slower, because there is actual work to do.

[barryvdh]

In theory it could usually copy the vendor dir from the previous release and then run composer install, but not sure how much that would speed up.

[staabm]

please use blackfire profilling (or similar) to measure where your time is spent

[barryvdh]

You could also run it with -vvv and add the --profile flag to composer.

[andrewtch]

Ok, I got the point.

This happens when there is no uzip command (@jolipixel, are you using clean DO droplet by any chance?) and / or zip PHP extension.

Vendors pass on such server always takes around 3-4 minutes as composer fallbacks to git clone. Installing unzip and adding:

add('copy_dirs', ['vendor']);
before('deploy:vendors', 'deploy:copy_dirs');

reduced times for copy_dirs to ~5s and vendors to ~4s.

[jolipixel]

This happens when there is no uzip command (@jolipixel, are you using clean DO droplet by any chance?) and / or zip PHP extension.

It was exactly that !

Deployment time went from ~112s to ~11s after :

apt-get install unzip
apt-get install php7.1-zip

Nice catch. Thank you.

[antonmedv]

Added check in deploy:vendors task for unzip command.