Doing a drush up on some servers is hanging on the command line.
Using "strace drush up" we can see where the problem occurs, right after building up the list of module versions in a /tmp/ file.

Here's the end of the strace right before drush hangs.

lstat("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=4096, ...}) = 0
lstat("/tmp/pm-updatecode.HPfxou", {st_mode=S_IFREG|0600, st_size=11446, ...}) = 0
open("/tmp/pm-updatecode.HPfxou", O_WRONLY|O_CREAT|O_APPEND, 0666) = 3
fstat(3, {st_mode=S_IFREG|0600, st_size=11446, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 0
lseek(3, 0, SEEK_CUR)                   = 0
write(3, "\n\nCode updates will be made to t"..., 84) = 84
close(3)                                = 0
dup(0)                                  = 3
fstat(3, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
fstat(3, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
lseek(3, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
read(3, ^C <unfinished ...>

Doing a cat/tail of the /tmp/pm-updatecode.HPfxou file shows a complete and formatted list of modules and their versions etc.

We've tried executing the drush command as normal users and the root user. Same problem. Stumped now.

Servers having the problem are:

Fedora 12 64bit
Ubuntu 10.04 64bit

Comments

budda’s picture

budda
Primary language English
Location Cheshire
commented
Issue tags: +filesystem, +lseek

Worth adding that the problem also occurs with Drush 3.x -- although the strace log is different:

lstat("/usr/share", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm/package_handler", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm/package_handler/wget.inc", {st_mode=S_IFREG|0644, st_size=3845, ...}) = 0
open("/usr/share/drush/commands/pm/package_handler/wget.inc", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=3845, ...}) = 0
stat("/usr/share/drush/commands/pm/package_handler/wget.inc", {st_mode=S_IFREG|0644, st_size=3845, ...}) = 0
read(4, "<?php\n// $Id: wget.inc,v 1.13 20"..., 8192) = 3845
read(4, "", 8192)                       = 0
read(4, "", 8192)                       = 0
close(4)                                = 0
dup(0)                                  = 4
fstat(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
fstat(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
lseek(4, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
read(4,  <unfinished ...>
greg.1.anderson’s picture

greg.1.anderson commented

Run top at the same time that you are doing the update and see if you are running out of memory, or anything unpleasant like that.

It is advisable to do updates on a copy of your site, not on the site itself. As a workaround, you could copy the live site to a dev machine on another server, do the update there, and then push the results back. If your site has a lot of active user content:

drush rsync @live @dev
drush sql-sync @live @dev
drush pm-update @dev
# test test test test
# take live offline
drush rsync @dev @live
drush @live updatedb
# bring live back online

I guess the big question here is whether the updatedb runs on the live site. If it does not, replace the part after test test test with:

# take live offline
drush sql-sync @live @dev
drush pm-update @dev # again
drush rsync @dev @live
drush sql-sync @dev @live
# bring live back online

Disclaimer: you may need or want to add options to these commands. Test and confirm carefully on your own. Keep rolling backups (or use a vcs) in case your "test test test" step turns out to be inadequate, and you find something after the fact.

greg.1.anderson’s picture

greg.1.anderson commented
Status: Active » Postponed (maintainer needs more info)
jonhattan’s picture

jonhattan
Primary language Spanish
Location Plasencia
commented

what's the exact command you're running? also post the --debug output.

chrishaslam’s picture

chrishaslam commented

Further to above checking error_logs etc there is no reference to memory being exhausted, and drush up does work for other sites on the same server

We are running drush -l dev.thedomain.co.uk up, here's the --debug below

Bootstrap to phase 0. [0.05 sec, 2.16 MB]                            [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drush() [0.05 sec, 2.39 MB] [bootstrap]
Bootstrap to phase 6. [0.12 sec, 5.53 MB]]                            [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_root() [0.12 sec, 5.54 MB] [bootstrap]
Initialized Drupal 6.19 root directory at /var/www/html/drupal-6.19 [0.15 sec, 6.44 MB]     [notice]
Drush bootstrap phase : _drush_bootstrap_drupal_site() [0.15 sec, 6.44 MB]     [bootstrap]
Initialized Drupal site bargainspy6.ixishosting.co.uk at sites/bargainspy6.ixishosting.co.uk [0.15 sec, 6.45 MB]  [notice]
Drush bootstrap phase : _drush_bootstrap_drupal_configuration() [0.17 sec, 6.45 MB] [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_database() [0.18 sec, 6.49 MB]  [bootstrap]
Successfully connected to the Drupal database. [0.18 sec, 6.49 MB] [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_full() [0.19 sec, 6.88 MB] [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_login() [0.64 sec, 31.68 MB]   [bootstrap]
Successfully logged into Drupal as Hunter (uid=0) [0.64 sec, 31.69 MB]  [bootstrap]
Found command: pm-update (commandfile=pm) [0.64 sec, 31.69 MB]   [bootstrap]
Initializing drush commandfile: user [0.64 sec, 31.7 MB] [bootstrap]
Including /usr/share/drush/commands/pm/updatecode.pm.inc [0.65 sec, 31.73 MB]  [bootstrap]
Extension comment_login is fetched from cvs. Ignoring. [3.58 sec, 42.16 MB]    [debug]
Extension fbconnect is fetched from cvs. Ignoring. [3.58 sec, 42.21 MB] [debug]
Extension fbconnect_profile is fetched from cvs. Ignoring. [3.58 sec, 42.21 MB]  [debug]
Extension returnpath is fetched from cvs. Ignoring. [3.58 sec, 42.39 MB]   [debug]
Extension webformblock is fetched from cvs. Ignoring. [3.58 sec, 42.5 MB]  [debug]
Downloading release history from http://updates.drupal.org/release-history/drush/6.x [3.6 sec, 42.66 MB] [notice]
Extension comment_login is fetched from cvs. Ignoring. [6.07 sec, 47.44 MB]   [debug]
Extension fbconnect is fetched from cvs. Ignoring. [6.07 sec, 47.5 MB] [debug]
Extension fbconnect_profile is fetched from cvs. Ignoring. [6.07 sec, 47.5 MB]  [debug]
Extension returnpath is fetched from cvs. Ignoring. [6.07 sec, 47.68 MB]  [debug]
Extension webformblock is fetched from cvs. Ignoring. [6.07 sec, 47.79 MB] [debug]
drush self-update check: drush 4.1 is up-to-date. [6.09 sec, 43.43 MB] [notice]

At this point drush hangs indefinitely, with the corresponding strace being:

write(2, "drush self-update check: drush 4"..., 152drush self-update check: drush 4.1 is up-to-date. [19.91 sec, 43.34 MB]                                                                        [notice]
) = 152
access("/usr/share/drush/commands/pm/package_handler/wget_6.inc", F_OK) = -1 ENOENT (No such file or directory)
access("/usr/share/drush/commands/pm/package_handler/wget.inc", F_OK) = 0
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm/package_handler", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/share/drush/commands/pm/package_handler/wget.inc", {st_mode=S_IFREG|0644, st_size=4189, ...}) = 0
lstat("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=1265664, ...}) = 0
lstat("/tmp/pm-updatecode.HuiLyB", {st_mode=S_IFREG|0600, st_size=5264, ...}) = 0
open("/tmp/pm-updatecode.HuiLyB", O_WRONLY|O_CREAT|O_APPEND, 0666) = 4
fstat(4, {st_mode=S_IFREG|0600, st_size=5264, ...}) = 0
lseek(4, 0, SEEK_CUR)                   = 0
lseek(4, 0, SEEK_CUR)                   = 0
write(4, "\n\nSecurity and code updates will"..., 632) = 632
close(4)                                = 0
dup(0)                                  = 4
fstat(4, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0
fstat(4, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0
lseek(4, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
clemens.tolboom’s picture

clemens.tolboom
Primary language Dutch
Location Groningen, 🇳🇱/🇪🇺
commented
Status: Postponed (maintainer needs more info) » Active

I did a --yes switch which 'solved' it.

drush --verbose --debug --yes upc calendar

But I found out that the drush_confirm is in err somehow. There is no prompt.

Following the hint to #499758: Prompt abort before user can answer there might be a prompt error again.

By typing y and enter runs the update. See #1041924: Drush up hangs after self-update check which sounds similar.

My env on Mac OS 10.6

$ php --version
PHP 5.3.3 (cli) (built: Aug 22 2010 19:41:55) 
Copyright (c) 1997-2010 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2010 Zend Technologies
    with Xdebug v2.1.0beta3, Copyright (c) 2002-2010, by Derick Rethans
clemens.tolboom’s picture

clemens.tolboom
Primary language Dutch
Location Groningen, 🇳🇱/🇪🇺
commented

Doing some further search http://www.google.nl/search?sourceid=chrome&ie=UTF-8&q=php+no+prompt+rea... I ended up on http://stackoverflow.com/questions/187736/command-line-password-prompt-i...

There is a php mention of stream_set_block and some php bug references. This http://bugs.php.net/bug.php?id=34972 sound interesting as it mentions php-5.3

But inspecting drush code

grep -r stream_set_blocking .drush
drush/includes/backend.inc:    stream_set_blocking($pipes[1], TRUE);
drush/includes/backend.inc:    stream_set_blocking($pipes[2], TRUE);
drush/includes/backend.inc:  stream_set_blocking($fp, FALSE);
drush/includes/drush.inc:  stream_set_blocking($stdin, TRUE);

I'm not sure this is related though as stdout is somehow not displayed right.

budda’s picture

budda
Primary language English
Location Cheshire
commented

--yes gets me past the problem.

The server PHP version is:

PHP 5.2.11 (cli) (built: Dec 13 2009 08:35:31) 
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.2.0, Copyright (c) 1998-2009 Zend Technologies
clemens.tolboom’s picture

clemens.tolboom
Primary language Dutch
Location Groningen, 🇳🇱/🇪🇺
commented

Today I used drush on same system but different local site and it worked.

Unfortunately I can't remember which site I did yesterday.

clemens.tolboom’s picture

clemens.tolboom
Primary language Dutch
Location Groningen, 🇳🇱/🇪🇺
commented

Both local sites are D6. One doesn't show the prompt (y/n) when running drush upc while the other does.

How can I investigate further?

Or should I first upgrade to the 4.2 version? This ticket is about the 4.1 version.

clemens.tolboom’s picture

clemens.tolboom
Primary language Dutch
Location Groningen, 🇳🇱/🇪🇺
commented

I just did a drush upc on the failed environment which is now working as expected. It prompts nicely. I don't understand :(

I'm updating modules so visited the /admin/reports/updates too to see the list. Cleared caches etc.

greg.1.anderson’s picture

greg.1.anderson commented
Status: Active » Fixed

Upgrade to drush-HEAD. See #1024824: Installing drush in $HOME/.drush can cause policy.drush.inc to force updatedb to abort mysteriously for the fix.

Workaround: move drush out of $HOME/.drush.

Status: Fixed » Closed (fixed)
Issue tags: -filesystem, -lseek

Automatically closed -- issue fixed for 2 weeks with no activity.

Issue tags: +filesystem, +lseek

Restoring issue tags, see #2125755: System messages removed all issue tags during D7 upgrade.