Wrong app path when optional PCNTL module was not enabled #335

Closed
PVince81 opened this Issue Apr 26, 2016 · 16 comments

Projects

None yet

2 participants

@PVince81
Contributor

Steps:

  1. Run updater and point it at patched daily because of #331
[info] Execution of upgrade:detect command started
[info] ownCloud 9.0.0.19 found
[info] Execution of upgrade:detect command stopped. Exit code is 0
[info] Execution of upgrade:checkSystem command started
[info] Execution of upgrade:checkSystem command stopped. Exit code is 0
[info] Execution of upgrade:checkpoint command started
[info] Execution of upgrade:checkpoint command stopped. Exit code is 0
[info] Execution of upgrade:detect command started
[info] ownCloud 9.0.0.19 found
[info] Execution of upgrade:detect command stopped. Exit code is 0
[info] Execution of upgrade:disableNotShippedApps command started
[info] Execution of upgrade:disableNotShippedApps command stopped. Exit code is 0
[info] Execution of upgrade:executeCoreUpgradeScripts command started
[debug] Moving config/config.sample.php
[debug] Moving core
[debug] Moving l10n
[debug] Moving lib
[debug] Moving ocs
[debug] Moving ocs-provider
[debug] Moving resources
[debug] Moving settings
[debug] Moving .htaccess
[debug] Moving .mailmap
[debug] Moving .tag
[debug] Moving .user.ini
[debug] Moving AUTHORS
[debug] Moving console.php
[debug] Moving COPYING-AGPL
[debug] Moving cron.php
[debug] Moving db_structure.xml
[debug] Moving index.html
[debug] Moving index.php
[debug] Moving indie.json
[debug] Moving occ
[debug] Moving public.php
[debug] Moving remote.php
[debug] Moving robots.txt
[debug] Moving status.php
[debug] Moving version.php
[info] Execution of upgrade:executeCoreUpgradeScripts command stopped. Exit code is 0
[info] Execution of upgrade:upgradeShippedApps command started
[error] 


  [Exception]                                                                                                                                                                                                                                        
  Unable to move /srv/www/htdocs/owncloudtest/_oc_upgrade/100.0.0.0/owncloud/apps/activity to The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php  
  /srv/www/htdocs/owncloudtest/apps/activity                                                                                                                                                                                                         



Exception trace:
 () at /srv/www/htdocs/owncloudtest/updater/src/Utils/FilesystemHelper.php:121
 Owncloud\Updater\Utils\FilesystemHelper->move() at /srv/www/htdocs/owncloudtest/updater/src/Command/UpgradeShippedAppsCommand.php:77
 Owncloud\Updater\Command\UpgradeShippedAppsCommand->execute() at /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Command/Command.php:256
 Symfony\Component\Console\Command\Command->run() at /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:838
 Symfony\Component\Console\Application->doRunCommand() at /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:127
 Owncloud\Updater\Console\Application->doRunCommand() at /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:189
 Symfony\Component\Console\Application->doRun() at /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:111
 Owncloud\Updater\Console\Application->doRun() at /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:120
 Symfony\Component\Console\Application->run() at /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:140
 Owncloud\Updater\Controller\IndexController->ajaxAction() at /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:88
 Owncloud\Updater\Controller\IndexController->dispatch() at /srv/www/htdocs/owncloudtest/updater/index.php:28


upgrade:upgradeShippedApps

Please add double quotes in debug messages.
From the message it looks like it's trying to move the folder to an empty string location.
I checked and saw that "_oc_upgrade/100.0.0.0/owncloud/apps/activity" exists.

@VicDeo @LukasReschke

@PVince81 PVince81 added this to the 9.0.2-current-maintenance milestone Apr 26, 2016
@PVince81
Contributor

Ah, I read it wrong. The target location is "/srv/www/htdocs/owncloudtest/apps/activity".

My apps folder is writable. However it looks like the apps haven't been deleted ?

/srv/www/htdocs/owncloudtest # ll apps
total 0
drwxr-xr-x 1 wwwrun www 132 Apr 26 11:58 activity
drwxr-xr-x 1 wwwrun www  48 Apr 26 11:58 comments
drwxr-xr-x 1 wwwrun www  34 Apr 26 11:58 dav
drwxr-xr-x 1 wwwrun www 122 Apr 26 11:58 encryption
drwxr-xr-x 1 wwwrun www 112 Apr 26 11:58 external
drwxr-xr-x 1 wwwrun www  28 Apr 26 11:58 federatedfilesharing
drwxr-xr-x 1 wwwrun www 170 Apr 26 11:58 federation
drwxr-xr-x 1 wwwrun www 204 Apr 26 11:58 files
drwxr-xr-x 1 wwwrun www 216 Apr 26 11:58 files_external
drwxr-xr-x 1 wwwrun www  80 Apr 26 11:58 files_pdfviewer
drwxr-xr-x 1 wwwrun www 190 Apr 26 11:58 files_sharing
drwxr-xr-x 1 wwwrun www  58 Apr 26 11:58 files_texteditor
drwxr-xr-x 1 wwwrun www 100 Apr 26 11:58 files_trashbin
drwxr-xr-x 1 wwwrun www  90 Apr 26 11:58 files_versions
drwxr-xr-x 1 wwwrun www  72 Apr 26 11:58 files_videoplayer
drwxr-xr-x 1 wwwrun www  90 Apr 26 11:58 firstrunwizard
drwxr-xr-x 1 wwwrun www 424 Apr 26 11:58 gallery
drwxr-xr-x 1 wwwrun www  78 Apr 26 11:58 notifications
drwxr-xr-x 1 wwwrun www  26 Apr 26 11:58 provisioning_api
drwxr-xr-x 1 wwwrun www  88 Apr 26 11:58 systemtags
drwxr-xr-x 1 wwwrun www 132 Apr 26 11:58 templateeditor
drwxr-xr-x 1 wwwrun www  88 Apr 26 11:58 updatenotification
drwxr-xr-x 1 wwwrun www  26 Apr 26 11:58 user_external
drwxr-xr-x 1 wwwrun www 232 Apr 26 11:58 user_ldap


/srv/www/htdocs/owncloudtest # ll _oc_upgrade/100.0.0.0/owncloud/apps/
total 0
drwxr-xr-x 1 wwwrun www 132 Apr 26 05:03 activity
drwxr-xr-x 1 wwwrun www  48 Apr 26 05:03 comments
drwxr-xr-x 1 wwwrun www  52 Apr 26 05:03 dav
drwxr-xr-x 1 wwwrun www 122 Apr 26 05:03 encryption
drwxr-xr-x 1 wwwrun www 112 Apr 26 05:01 external
drwxr-xr-x 1 wwwrun www  28 Apr 26 05:03 federatedfilesharing
drwxr-xr-x 1 wwwrun www 170 Apr 26 05:03 federation
drwxr-xr-x 1 wwwrun www 204 Apr 26 05:03 files
drwxr-xr-x 1 wwwrun www 216 Apr 26 05:03 files_external
drwxr-xr-x 1 wwwrun www  80 Apr 26 05:03 files_pdfviewer
drwxr-xr-x 1 wwwrun www 190 Apr 26 05:03 files_sharing
drwxr-xr-x 1 wwwrun www  58 Apr 26 05:03 files_texteditor
drwxr-xr-x 1 wwwrun www 100 Apr 26 05:03 files_trashbin
drwxr-xr-x 1 wwwrun www  90 Apr 26 05:03 files_versions
drwxr-xr-x 1 wwwrun www  72 Apr 26 05:03 files_videoplayer
drwxr-xr-x 1 wwwrun www  90 Apr 26 05:03 firstrunwizard
drwxr-xr-x 1 wwwrun www 424 Apr 26 05:03 gallery
drwxr-xr-x 1 wwwrun www  78 Apr 26 05:03 notifications
drwxr-xr-x 1 wwwrun www  26 Apr 26 05:03 provisioning_api
drwxr-xr-x 1 wwwrun www  88 Apr 26 05:03 systemtags
drwxr-xr-x 1 wwwrun www 132 Apr 26 05:03 templateeditor
drwxr-xr-x 1 wwwrun www  88 Apr 26 05:03 updatenotification
drwxr-xr-x 1 wwwrun www  26 Apr 26 05:03 user_external
drwxr-xr-x 1 wwwrun www 232 Apr 26 05:03 user_ldap
@PVince81
Contributor

Permissions are correct it seems:

/srv/www/htdocs/owncloudtest # ls -ld apps
drwxrwxr-x 1 wwwrun www 578 Apr 26 11:58 apps

Might be connected to the "_apps" folder symptom.

Why wouldn't the updater be able to properly move apps ?
And if it doesn't, it seems the workaround doesn't work either.

@VicDeo VicDeo was assigned by PVince81 Apr 26, 2016
@LukasReschke LukasReschke referenced this issue in owncloud/core Apr 26, 2016
Closed

Also exclude __apps #24273

@VicDeo
Member
VicDeo commented Apr 26, 2016

@PVince81 in Unable to move /srv/www/htdocs/owncloudtest/_oc_upgrade/100.0.0.0/owncloud/apps/activity to The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php /srv/www/htdocs/owncloudtest/apps/activity

to The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php is the most interesting part.

who was going to interrupt long running commands here?

@PVince81
Contributor

@VicDeo you can ignore this message. It appears when someone doesn't have php's PCNTL extension enabled which makes it possible for PHP to catch Ctrl+C events on the CLI for proper cleanup (used currently for files:scan and other comments).
I don't think this is interfering.

It seems that for some reason the updater wasn't able to move away / delete the contents of my "apps/" folder and this caused the series of issue we saw today.

@PVince81
Contributor

Same error in error_log:

[Tue Apr 26 12:45:36.261599 2016] [authz_core:error] [pid 24965] [client 127.0.0.1:60508] AH01630: client denied by server configuration: /srv/www/htdocs/owncloudtest/data/.ocdata
[Tue Apr 26 12:46:09.780728 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP Warning:  rename(/srv/www/htdocs/owncloudtest/_oc_upgrade/100.0.0.0/owncloud/apps/activity,The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php\n/srv/www/htdocs/owncloudtest/apps/activity): No such file or directory in /srv/www/htdocs/owncloudtest/updater/src/Utils/FilesystemHelper.php on line 120
[Tue Apr 26 12:46:09.780763 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP Stack trace:
[Tue Apr 26 12:46:09.780779 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   1. {main}() /srv/www/htdocs/owncloudtest/updater/index.php:0
[Tue Apr 26 12:46:09.780789 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   2. Owncloud\\Updater\\Controller\\IndexController->dispatch() /srv/www/htdocs/owncloudtest/updater/index.php:28
[Tue Apr 26 12:46:09.780797 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   3. Owncloud\\Updater\\Controller\\IndexController->ajaxAction() /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:88
[Tue Apr 26 12:46:09.780805 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   4. Symfony\\Component\\Console\\Application->run() /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:140
[Tue Apr 26 12:46:09.780812 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   5. Owncloud\\Updater\\Console\\Application->doRun() /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:120
[Tue Apr 26 12:46:09.780819 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   6. Symfony\\Component\\Console\\Application->doRun() /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:111
[Tue Apr 26 12:46:09.780826 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   7. Owncloud\\Updater\\Console\\Application->doRunCommand() /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:189
[Tue Apr 26 12:46:09.780832 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   8. Symfony\\Component\\Console\\Application->doRunCommand() /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:127
[Tue Apr 26 12:46:09.780838 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP   9. Symfony\\Component\\Console\\Command\\Command->run() /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:838
[Tue Apr 26 12:46:09.780845 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP  10. Owncloud\\Updater\\Command\\UpgradeShippedAppsCommand->execute() /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Command/Command.php:256
[Tue Apr 26 12:46:09.780853 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP  11. Owncloud\\Updater\\Utils\\FilesystemHelper->move() /srv/www/htdocs/owncloudtest/updater/src/Command/UpgradeShippedAppsCommand.php:77
[Tue Apr 26 12:46:09.780859 2016] [php5:error] [pid 24965] [client 127.0.0.1:60508] PHP  12. rename() /srv/www/htdocs/owncloudtest/updater/src/Utils/FilesystemHelper.php:120
[Tue Apr 26 13:01:42.729116 2016] [authz_core:error] [pid 16315] [client 127.0.0.1:33390] AH01630: client denied by server configuration: /srv/www/htdocs/owncloudtest/data/.ocdata
[Tue Apr 26 13:04:54.095679 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP Fatal error:  Class 'OCA\\Files_Sharing\\API\\Server2Server' not found in /srv/www/htdocs/owncloudtest/ocs/routes.php on line 102
[Tue Apr 26 13:04:54.095703 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP Stack trace:
[Tue Apr 26 13:04:54.095715 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP   1. {main}() /srv/www/htdocs/owncloudtest/index.php:0
[Tue Apr 26 13:04:54.095721 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP   2. OC::handleRequest() /srv/www/htdocs/owncloudtest/index.php:39
[Tue Apr 26 13:04:54.095725 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP   3. OC\\Route\\Router->match($url = *uninitialized*) /srv/www/htdocs/owncloudtest/lib/base.php:882
[Tue Apr 26 13:04:54.095729 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP   4. OC\\Route\\Router->loadRoutes($app = *uninitialized*) /srv/www/htdocs/owncloudtest/lib/private/route/router.php:247
[Tue Apr 26 13:04:54.095733 2016] [php5:error] [pid 2420] [client 127.0.0.1:33584] PHP   5. require_once() /srv/www/htdocs/owncloudtest/lib/private/route/router.php:159
[Tue Apr 26 13:13:14.156725 2016] [mpm_prefork:notice] [pid 6366] AH00170: caught SIGWINCH, shutting down gracefully
[Tue Apr 26 13:13:14.162255 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP Warning:  rename(/srv/www/htdocs/owncloudtest/apps,/srv/www/htdocs/owncloudtest/__apps): Directory not empty in /srv/www/htdocs/owncloudtest/updater/src/Utils/FilesystemHelper.php on line 129
[Tue Apr 26 13:13:14.162286 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP Stack trace:
[Tue Apr 26 13:13:14.162298 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   1. {main}() /srv/www/htdocs/owncloudtest/updater/index.php:0
[Tue Apr 26 13:13:14.162308 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   2. Owncloud\\Updater\\Controller\\IndexController->dispatch() /srv/www/htdocs/owncloudtest/updater/index.php:28
[Tue Apr 26 13:13:14.162317 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   3. Owncloud\\Updater\\Controller\\IndexController->ajaxAction() /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:88
[Tue Apr 26 13:13:14.162326 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   4. Symfony\\Component\\Console\\Application->run($input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/src/Controller/IndexController.php:140
[Tue Apr 26 13:13:14.162334 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   5. Owncloud\\Updater\\Console\\Application->doRun($input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:120
[Tue Apr 26 13:13:14.162342 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   6. Symfony\\Component\\Console\\Application->doRun($input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:135
[Tue Apr 26 13:13:14.162350 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   7. Owncloud\\Updater\\Console\\Application->doRunCommand($command = *uninitialized*, $input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:189
[Tue Apr 26 13:13:14.162358 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   8. Symfony\\Component\\Console\\Application->doRunCommand($command = *uninitialized*, $input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/src/Console/Application.php:158
[Tue Apr 26 13:13:14.162365 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP   9. Symfony\\Component\\Console\\Command\\Command->run($input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Application.php:838
[Tue Apr 26 13:13:14.162374 2016] [php5:error] [pid 7192] [client 127.0.0.1:34074] PHP  10. Owncloud\\Updater\\Command\\ExecuteCoreUpgradeScriptsCommand->execute($input = *uninitialized*, $output = *uninitialized*) /srv/www/htdocs/owncloudtest/updater/vendor/symfony/console/Command/Command.php:256

Unfortunately no clue about the first failed move, maybe the error was inhibited ?

@PVince81
Contributor

Possibly related to #318 since now we do copy + delete instead of move.

@PVince81
Contributor

Hmm no, I started with 9.0.0, so that updater version was still using move.

@PVince81
Contributor

Strange, now I can't reproduce it.
The one thing I changed is that I installed the module php5-pnctl.

I'll try again removing it, maybe it inteferes somehow.

@PVince81
Contributor

Okay, now after removing the module "php5-pnctl" the error happens again.
I'll do a few more runs to confirm that.

The module "php5-pnctl" is optional, so we can't expect everyone to have it installed.

@VicDeo is the updater parsing the output of the command and expecting something, and fails if it doesn't match ?

@PVince81
Contributor

And here we go, confirmed:

$oldPath                         = (string[192]) 'The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php
/srv/www/htdocs/owncloudtest/apps/activity';

Seems the updater is expecting the output to contain no warning.

@PVince81
Contributor

Looks like this message goes to stdout, not stderr, so there is no easy way to filter it out.
With a bit of luck there might be a newline, so you'd need to read only the last row of the output.

We could try making it output to stderr instead: https://github.com/owncloud/core/blob/v9.0.1/console.php#L89
In general, all warnings should be output to stderr, I see there are more above.

@PVince81
Contributor

Yeah, sorry. Before copied the url I replaced "master" with "v9.0.1" so the lines have shifted.

I have a local fix for core, will test whether the updater properly ignores stderr.

@PVince81
Contributor

I see there is also code for "--no-warnings", so maybe you forgot to call all commands with that option ?

@PVince81
Contributor

Bad luck, even with STDERR the updater app still parses the message.

Short term I suggest to look into why "--no-warnings" isn't passed (the option works when invoked manually).

@PVince81 PVince81 changed the title from Exception when moving app during update to Wrong app path when optional PCNTL module was not enabled Apr 26, 2016
@PVince81
Contributor

Fix is here #339

@PVince81 PVince81 closed this Apr 26, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment