NPM install causes deploy to cancel with exception 'Pheanstalk\Exception\ServerException' with message 'Server reported NOT_FOUND'

[kamioftea]

Before submitting your issue, please make sure that you've checked all of the checkboxes below.

• [x] You're running the latest release version of Deployer. I have tried with both 0.0.46 and master
• [x] Ensure that you're running at least PHP 5.6.4, you can check this by running php -v
• [x] You've ran composer install --no-dev from the root of your installation.
• [x] You've ran npm install --production from the root of your installation.
• [x] You've ran rm -rf bootstrap/cache/* from the root of your installation.
• [x] You have restarted the queue listener and node socket server.

To help us better understand your issue, please answer the following.

This is possibly related to #333 I have followed the advice at the bottom of that thread to update to master and I'm still experiencing the issue.

Expected behaviour

Deployer to run npm install command on remote server.

Actual behaviour

As soon as the command executes npm install the remaining steps in the deploy are marked as cancelled, but the running command still shows as running. The below stack trace is logged at the same time. Sometimes a snippet of the start of the npm command is shown in the console log, e.g.

But normally there is no output logged before the deploy fails.

As there are multiple javascript modules to build I have a find command that locates them and uses xargs runs npm install for each. In this case the command runs successfully until the first invocation of npm install at which point it errors as described. As part of debugging I have setup the command with each npm install set included manually. In this case the command errors almost immediately - as soon as the first npm install is executed.

Steps to reproduce

Include a command in a deploy that executes npm install

Environment info

Laravel Environment

• Laravel Version: 5.4.36
• Timezone: Europe/London
• Debug Mode: ✘
• Storage Dir Writable: ✔
• Cache Dir Writable: ✔
• Decomposer Version: ^1.0
• App Size: 283 MB

Server Environment

• PHP Version: 5.6.35-1+ubuntu14.04.1+deb.sury.org+1
• Server Software: nginx/1.4.6
• Server OS: Linux crushinator 3.13.0-145-generic #194-Ubuntu SMP Thu Apr 5 15:20:44 UTC 2018 x86_64
• Database: mysql
• SSL Installed: ✘
• Cache Driver: file
• Session Driver: file
• Openssl Ext: ✔
• PDO Ext: ✔
• Mbstring Ext: ✔
• Tokenizer Ext: ✔
• XML Ext: ✔
• Curl Ext: ✔
• GD Ext: ✔
• JSON Ext: ✔

Installed Packages & their version numbers

• andywer/js-localization : dev-laravel-5
• backup-manager/laravel : ^1.1
• creativeorange/gravatar : ~1.0
• cweagans/composer-patches : ^1.6
• doctrine/dbal : ~2.5
• fideloper/proxy : ^3.1
• graham-campbell/binput : ~3.3
• htmlmin/htmlmin : ~4.5
• guzzlehttp/guzzle : ^6.2
• intervention/image : ^2.3
• laracademy/interactive-make : ^1.1
• laravel-notification-channels/hipchat : ~0.2
• laravel-notification-channels/twilio : ~1.0.2
• laravel-notification-channels/webhook : ~1.0.2
• laravel/framework : ^5.4
• laravel/tinker : 1.0.*
• lubusin/laravel-decomposer : ^1.0
• mccool/laravel-auto-presenter : ^5.0
• melihovv/laravel-log-viewer : ^1.2
• michele-angioni/multi-language : 0.3
• pda/pheanstalk : ~3.1
• pragmarx/google2fa : ^1.0.0
• predis/predis : ~1.0
• tymon/jwt-auth : ~0.5
• rebelinblue/laravel5-zxcvbn : dev-master
• version/version : ^2.2

Extra Information

• proc_open enabled : ✔

Node

• node -v v6.14.1
• npm -v 3.10.10

Logs (see storage/logs/) or other output that would be helpful

from: cli-2018-04-27.log

[2018-04-27 14:25:23] production.ERROR: exception 'Pheanstalk\Exception\ServerException' with message 'Server reported NOT_FOUND' in /var/www/deploy.hightechclick.com/vendor/pda/pheanstalk/src/YamlResponseParser.php:36
Stack trace:
#0 /var/www/deploy.hightechclick.com/vendor/pda/pheanstalk/src/Connection.php(142): Pheanstalk\YamlResponseParser->parseResponse('NOT_FOUND', NULL)
#1 /var/www/deploy.hightechclick.com/vendor/pda/pheanstalk/src/Pheanstalk.php(396): Pheanstalk\Connection->dispatchCommand(Object(Pheanstalk\Command\StatsJobCommand))
#2 /var/www/deploy.hightechclick.com/vendor/pda/pheanstalk/src/Pheanstalk.php(312): Pheanstalk\Pheanstalk->_dispatch(Object(Pheanstalk\Command\StatsJobCommand))
#3 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Jobs/BeanstalkdJob.php(91): Pheanstalk\Pheanstalk->statsJob(Object(Pheanstalk\Job))
#4 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(405): Illuminate\Queue\Jobs\BeanstalkdJob->attempts()
#5 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(349): Illuminate\Queue\Worker->markJobAsFailedIfWillExceedMaxAttempts('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob), 1, Object(Pheanstalk\Exception\ServerException))
#6 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(321): Illuminate\Queue\Worker->handleJobException('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob), Object(Illuminate\Queue\WorkerOptions), Object(Pheanstalk\Exception\ServerException))
#7 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(267): Illuminate\Queue\Worker->process('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob), Object(Illuminate\Queue\WorkerOptions))
#8 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(113): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\BeanstalkdJob), 'beanstalkd', Object(Illuminate\Queue\WorkerOptions))
#9 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(102): Illuminate\Queue\Worker->daemon('beanstalkd', 'deployer-high,d...', Object(Illuminate\Queue\WorkerOptions))
#10 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(86): Illuminate\Queue\Console\WorkCommand->runWorker('beanstalkd', 'deployer-high,d...')
#11 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#12 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(30): call_user_func_array(Array, Array)
#13 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#14 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure))
#15 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Container/Container.php(539): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL)
#16 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Console/Command.php(182): Illuminate\Container\Container->call(Array)
#17 /var/www/deploy.hightechclick.com/vendor/symfony/console/Command/Command.php(252): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
#18 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Console/Command.php(168): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
#19 /var/www/deploy.hightechclick.com/vendor/symfony/console/Application.php(946): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#20 /var/www/deploy.hightechclick.com/vendor/symfony/console/Application.php(248): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#21 /var/www/deploy.hightechclick.com/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#22 /var/www/deploy.hightechclick.com/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(122): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#23 /var/www/deploy.hightechclick.com/artisan(46): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#24 {main}

[REBELinBLUE]

Is the command simply npm install ?

Could you share the package.json if possible?

[kamioftea]

The commands tried have been:

find {{ release_path }} -name "webpack.production.config.js" ! -path "*/node_modules/*" -print0 | xargs -0 -I path /bin/sh -c 'cd "$(dirname path)"; npm install; npm run build --if-present'

Which runs until find matches a file, and xargs calls npm install. This was previously working in 0.0.45.

I also tried setting up a command to install and build a specific module:

cd {{release_path}}/modules/ThirdParty/view/third-party/third-party-approval/react
npm install
npm run build

And again this executed the cd ... and then failed on running npm install.

The package.json is:

{
  "name": "third-party-approvals",
  "version": "0.0.1",
  "description": "Third party approval page app",
  "author": "Jeff Horton <[email protected]>",
  "scripts": {
    "start": "webpack --config webpack.development.config.js -w --progress",
    "build": "webpack --config webpack.production.config.js --define process.env.NODE_ENV=\"'production'\""
  },
  "dependencies": {
    "babel-cli": "^6.26.0",
    "babel-loader": "^7.1.4",
    "babel-plugin-transform-object-rest-spread": "^6.26.0",
    "babel-polyfill": "^6.26.0",
    "babel-preset-env": "^1.6.1",
    "babel-preset-react": "^6.24.1",
    "css-loader": "^0.28.11",
    "draft-js": "^0.10.5",
    "immutable": "^3.8.2",
    "json-loader": "^0.5.7",
    "mini-css-extract-plugin": "^0.4.0",
    "npm": "^5.8.0",
    "optimize-css-assets-webpack-plugin": "^4.0.0",
    "react": "^16.3.2",
    "react-dom": "^16.3.2",
    "react-dropzone": "^4.2.9",
    "react-redux": "^5.0.7",
    "redux": "^3.7.2",
    "redux-observable": "^0.18.0",
    "rxjs": "^5.5.10",
    "uglify-es": "^3.3.10",
    "uglifyjs-webpack-plugin": "^1.2.5",
    "url-loader": "^1.0.1",
    "webpack": "^4.6.0",
    "webpack-cli": "^2.0.15",
    "webpack-stream": "^4.0.3"
  }
}

[REBELinBLUE]

Really sorry for the late reply, I'd missed you reply.

If it isn't working still can you run artisan app:debug, then try a deploy again and share the latest whole

[kamioftea]

I've updated to the current master and run a deploy. Here are the logs produced from server startup, then running the deploy at 12:04:02, which failed at 12:09:14.

deployer_logs.zip

Let me know if there's anything else you need.

Thanks.

[kamioftea]

I have managed to work around this by silencing output from the commands using > /dev/null 2>&1. From trial and error it seems to be something to do with the various command characters for color/cursor position used by npm/webpack.