php takes up 100% CPU on drush @hostmaster status [#2047863]

Weirdest thing - during the aegir debian package upgrade of 1.9 to 1.10, I saw drush @hostmaster status just freeze there. Puzzled, I ran it in strace, and lo and behold, it did it again!

The freeze happens after the alias discovery, when drush is about to finish bootstrapping drupal:

aegir@ceres:~/.drush$ drush -d @hostmaster status
Bootstrap to phase 0. [0.01 sec, 2.79 MB]                            [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drush() [0.02 sec, 3.01 MB] [bootstrap]
Load alias @hostmaster [0.02 sec, 3.02 MB]                                                                     [notice]
Loading drushrc "/srv/aegir/hostmaster-6.x-1.x/sites/aegir.koumbit.net/drushrc.php" into "site" scope. [0.03[bootstrap]
sec, 3.03 MB]
Drush bootstrap phase : _drush_bootstrap_drupal_root() [0.1 sec, 13.83 MB]                                  [bootstrap]
Loading drushrc "/srv/aegir/hostmaster-6.x-1.x/drushrc.php" into "drupal" scope. [0.1 sec, 13.83 MB]        [bootstrap]
Initialized Drupal 6.28 root directory at /srv/aegir/hostmaster-6.x-1.x [0.12 sec, 15.67 MB]                   [notice]
Drush bootstrap phase : _drush_bootstrap_drupal_site() [0.12 sec, 15.67 MB]                                 [bootstrap]
Initialized Drupal site aegir.koumbit.net at sites/aegir.koumbit.net [0.12 sec, 15.67 MB]                      [notice]
Loading drushrc "/srv/aegir/hostmaster-6.x-1.x/sites/aegir.koumbit.net/drushrc.php" into "site" scope. [0.12[bootstrap]
sec, 15.68 MB]
Drush bootstrap phase : _drush_bootstrap_drupal_configuration() [0.12 sec, 15.68 MB]                        [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_database() [0.13 sec, 15.75 MB]                             [bootstrap]
Successfully connected to the Drupal database. [0.13 sec, 15.75 MB]                                         [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_full() [0.13 sec, 16.13 MB]                                 [bootstrap]
Drush bootstrap phase : _drush_bootstrap_drupal_login() [0.33 sec, 45.48 MB]                                [bootstrap]
Successfully logged into Drupal as Anonymous (uid=0) [0.33 sec, 45.49 MB]                                   [bootstrap]
Found command: core-status (commandfile=core) [0.33 sec, 45.49 MB]                                          [bootstrap]
Initializing drush commandfile: drush_make [0.33 sec, 45.5 MB]                                              [bootstrap]
Initializing drush commandfile: drush_make_d_o [0.33 sec, 45.5 MB]                                          [bootstrap]
Initializing drush commandfile: provision [0.33 sec, 45.5 MB]                                               [bootstrap]
Load alias @server_mysqlaegirkoumbitnet [0.33 sec, 45.52 MB]                                                   [notice]
Load alias @server_master [0.34 sec, 45.54 MB]                                                                 [notice]
Loading apache_ssl driver for the http service [0.35 sec, 45.57 MB]                                            [notice]
Loading mysql driver for the db service [0.36 sec, 45.64 MB]                                                   [notice]
Load alias @platform_hostmaster6x1x [0.36 sec, 45.65 MB]                                                       [notice]
Initializing drush commandfile: provision_civicrm [0.37 sec, 45.66 MB]                                      [bootstrap]
Initializing drush commandfile: user [0.37 sec, 45.67 MB]                                                   [bootstrap]
[... freeze here! ...]

This affects actually all sites hosted on aegir. It as if there was a loop somewhere...

Comments

Comment #1

anarcat CreditAttribution: anarcat commented 22 July 2013 at 20:50

The remaining of the output:

 Drupal version        :  6.28
 Site URI              :  aegir.koumbit.net
 Database driver       :  mysqli
 Database hostname     :  mysql.aegir.koumbit.net
 Database username     :  aegirkoumbitnet
 Database name         :  aegirkoumbitnet
 Database              :  Connected
 Drupal bootstrap      :  Successful
 Drupal user           :  Anonymous
 Default theme         :  eldir_kt
 Administration        :  eldir_kt
 theme
 PHP configuration     :  /etc/php5/cli/php.ini
 Drush version         :  4.5
 Drush configuration   :  /srv/aegir/hostmaster-6.x-1.x/sites/aegir.koumbit.net/drushrc.php
                          /srv/aegir/hostmaster-6.x-1.x/drushrc.php
 Drush alias files     :  /var/aegir/.drush/hostmaster.alias.drushrc.php
                          /var/aegir/.drush/server_mysqlaegirkoumbitnet.alias.drushrc.php
                          /var/aegir/.drush/server_master.alias.drushrc.php
                          /var/aegir/.drush/platform_hostmaster6x1x.alias.drushrc.php
[... a metric ton of aliases ...]
 Drupal root           :  /srv/aegir/hostmaster-6.x-1.x
 Site path             :  sites/aegir.koumbit.net
 File directory path   :  sites/aegir.koumbit.net/files

Command dispatch complete [305.05 sec, 48.08 MB]                                                               [notice]
 Timer  Cum (sec)  Count  Avg (msec)
 page   304.924    1      304924.24

Peak memory usage was 72.99 MB [305.05 sec, 48.07 MB]                                                          [memory]

Yes, 5 minutes. I believe the is the console table struggling to render that huge table of aliases.

Comment #2

anarcat CreditAttribution: anarcat commented 22 July 2013 at 20:55

oh dear, this is actually #1132902: performance issues with huge tables rearing its ugly head again... i *think* this is somewaht fixed (aka workaround) in Drush 5 because of #1132906: lazy-loading of drush aliases, but unfortunately, it clearly is a problem in drush 4 still, and may also be if a lot of aliases end up being loaded for some reason.

Comment #3

ergonlogic

he/him

English

Montréal, Québec 🇨🇦

CreditAttribution: ergonlogic commented 24 July 2013 at 16:21

Just to clarify, this is only an issue when running 'drush status' manually, or during the package scripts, right? Status isn't used in normal Aegir operations, iirc. Could we run the 'drush @hostmaster status' under nice in the .deb script, maybe, to avoid locking the system?