Page MenuHomePhabricator

Mediawiki-Vagrant role "Wikidata" fails after timeout
Open, Needs TriagePublic

Description

It seems like Mediawiki-Vagrant fails after a timeout.

john@hydra:~/wbspace$ git clone --recursive https://gerrit.wikimedia.org/r/mediawiki/vagrant .
john@hydra:~/wbspace$ ./setup.sh
john@hydra:~/wbspace$ vagrantup

At this point I log into the box and run

vagrant@mediawiki-vagrant:~$ curl -sS https://getcomposer.org/installer | php

When done I continue with

john@hydra:~/wbspace$ vagrant enable-role wikidata
john@hydra:~/wbspace$ vagrant provision

and here things start to break down after some output

==> default: Info: Mediawiki::Wiki[fr]: Scheduling refresh of Mediawiki::Maintenance[wikidata-populate-site-tables]
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Git::Clone[mediawiki/extensions/WikidataBuildResources]/File[/vagrant/mediawiki/extensions/WikidataBuildResources]/ensure: created
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Git::Clone[mediawiki/extensions/WikidataBuildResources]/Exec[git_clone_mediawiki/extensions/WikidataBuildResources]/returns: executed successfully
==> default: Notice: /Stage[main]/Role::Langwikis/Mediawiki::Langwiki[fr]/Mediawiki::Settings[frwiki settings]/File[/vagrant/settings.d/wikis/frwiki/settings.d/puppet-managed/10-frwiki-settings.php]/ensure: created
==> default: Error: Command exceeded timeout
==> default: Error: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Php::Composer::Install[/vagrant/mediawiki/extensions/WikidataBuildResources]/Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources]/returns: change from notrun to 0 failed: Command exceeded timeout
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]: Skipping because of failed dependencies

…

==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Git::Clone[mediawiki/services/jobrunner]/Exec[git_clone_mediawiki/services/jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/File[/etc/init/jobrunner.conf]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/File[/etc/init/jobrunner.conf]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Service[jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Service[jobrunner]: Skipping because of failed dependencies
==> default: Notice: Finished catalog run in 1077.72 seconds
The SSH command responded with a non-zero exit status. Vagrant
assumes that this means the command failed. The output for this command
should be in the log above. Please read the output to determine what
went wrong.

Note that the role is called "Wikidata", but this is probably more like "Wikibase-dev" or something similar.

Event Timeline

jeblad created this task.Nov 12 2016, 4:20 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptNov 12 2016, 4:20 PM
jeblad renamed this task from Role Wikidata fails after timeout to Mediawiki-Vagrant role "Wikidata" fails after timeout.Nov 12 2016, 4:24 PM
jeblad updated the task description. (Show Details)
jeblad updated the task description. (Show Details)Nov 12 2016, 4:30 PM
jeblad updated the task description. (Show Details)Nov 12 2016, 10:59 PM

This can be the composer timeout. I will try a rerun on a fresh install.

Sn1per added a subscriber: Sn1per.Dec 3 2016, 6:24 AM
Sn1per added a comment.EditedDec 3 2016, 4:29 PM

I get this issue with the LXC provider, but not with virtualbox.

Nevermind, spoke too soon.

aude added a subscriber: aude.Jan 8 2017, 3:29 AM

It looks like the issue is that composer install timed out.

The default timeout for composer is 300s. This was sufficient for me to enable the Wikidata role / install Wikibase, but maybe could be an issue for others. (not vagrant specific issue, but general issue)

It looks like an environment variable can be set (COMPOSER_PROCESS_TIMEOUT) to increase that, and is something we can have vagrant do.

Change 331207 had a related patch set uploaded (by Aude):
Set COMPOSER_PROCESS_TIMEOUT to 600

https://gerrit.wikimedia.org/r/331207

I have no clear understanding of what is the real root cause of this problem, but suddenly the Vagrant box started to work.

Here is a rough writeup of what happen

  • Vagrantfile-extra.rb to set mem to 3072 and cpus to 2
  • composer config --global process-timeout 900

Did a vagrant provision, and it failed yet another time.

  • vagrant destroy
  • vagrant global-status --prune
  • vagrant disable wikidata (?)
  • vagrant up
  • vagrant git-update

In another terminal I logged in to the client

  • vagrant ssh
  • composer config --global process-timeout 4800
  • sudo locale-gen nb
  • sudo locale-gen nn
  • sudo locale-gen no
  • sudo locale-gen en
  • sudo locale-gen es
  • sudo locale-gen he
  • sudo locale-gen ru
  • sudo locale-gen zh
  • sudo dpkg-reconfigure locales
  • sudo update-locale LANG=nb_NO.UTF-8
  • sudo apt-get update && sudo apt-get upgrade

Back on the host

  • vagrant enable-role wikidata
  • VAGRANT_LOG=info vagrant provision

I suspect that the first failed boot did load the composer cache, and that it was unnecessary for me to increase the timeout further, but still 2400 sec is not sufficient to avoid a timeout on my setup. It could perhaps be that NFS creates the timeout, but I'm not sure.

The culprit is somewhere in the following sequence, and after line 6

 INFO interface: info: Info: Mediawiki::Wiki[fr]: Scheduling refresh of Mediawiki::Maintenance[wikidata-populate-site-tables]
 INFO interface: info: ==> default: Info: Mediawiki::Wiki[fr]: Scheduling refresh of Mediawiki::Maintenance[wikidata-populate-site-tables]
==> default: Info: Mediawiki::Wiki[fr]: Scheduling refresh of Mediawiki::Maintenance[wikidata-populate-site-tables]
 INFO interface: info: Notice: /Stage[main]/Role::Langwikis/Mediawiki::Langwiki[fr]/Mediawiki::Settings[frwiki settings]/File[/vagrant/settings.d/wikis/frwiki/settings.d/puppet-managed/10-frwiki-settings.php]/ensure: created
 INFO interface: info: ==> default: Notice: /Stage[main]/Role::Langwikis/Mediawiki::Langwiki[fr]/Mediawiki::Settings[frwiki settings]/File[/vagrant/settings.d/wikis/frwiki/settings.d/puppet-managed/10-frwiki-settings.php]/ensure: created
==> default: Notice: /Stage[main]/Role::Langwikis/Mediawiki::Langwiki[fr]/Mediawiki::Settings[frwiki settings]/File[/vagrant/settings.d/wikis/frwiki/settings.d/puppet-managed/10-frwiki-settings.php]/ensure: created
 INFO interface: info: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]/ensure: created
 INFO interface: info: ==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]/ensure: created
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]/ensure: created
 INFO interface: info: Info: Mediawiki::Settings[WikidataBuildResources]: Scheduling refresh of Exec[update_all_databases]
 INFO interface: info: ==> default: Info: Mediawiki::Settings[WikidataBuildResources]: Scheduling refresh of Exec[update_all_databases]
==> default: Info: Mediawiki::Settings[WikidataBuildResources]: Scheduling refresh of Exec[update_all_databases]
 INFO interface: info: Notice: /Stage[main]/Role::Sitematrix/Mediawiki::Extension[SiteMatrix]/Mediawiki::Settings[SiteMatrix]/File[/vagrant/settings.d/puppet-managed/10-SiteMatrix.php]/ensure: created

Nope, can't reproduce.

A little digging; client and repo isn't available when the build resource tries to access them. It could be due to a previous failure, but could also be because of some failed assumption.

Change 331207 merged by jenkins-bot:
Set COMPOSER_PROCESS_TIMEOUT to 600 for composer install

https://gerrit.wikimedia.org/r/331207

Thanks, this works for me now.

I raise the same issue:

==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Git::Clone[mediawiki/extensions/WikidataBuildResources]/File[/vagrant/mediawiki/extensions/WikidataBuildResources]/ensure: created
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Git::Clone[mediawiki/extensions/WikidataBuildResources]/Exec[git_clone_mediawiki/extensions/WikidataBuildResources]/returns: executed successfully
==> default: Error: Command exceeded timeout
==> default: Error: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Php::Composer::Install[/vagrant/mediawiki/extensions/WikidataBuildResources]/Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources]/returns: change from notrun to 0 failed: Command exceeded timeout
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Mediawiki::Extension[WikidataBuildResources]/Mediawiki::Settings[WikidataBuildResources]/File[/vagrant/settings.d/puppet-managed/10-WikidataBuildResources.php]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki/Exec[update_all_databases]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki/Exec[update_all_databases]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Role::Wikidata/Exec[wikidata-update-git-remote]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Exec[wikidata-update-git-remote]: Skipping because of failed dependencies
==> default: Info: Mediawiki::Maintenance[wikidata-populate-site-tables]: Scheduling refresh of Exec[wikidata-populate-site-tables]
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Maintenance[wikidata-populate-site-tables]/Exec[wikidata-populate-site-tables]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Mediawiki::Maintenance[wikidata-populate-site-tables]/Exec[wikidata-populate-site-tables]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Maintenance[wikidata-populate-site-tables]/Exec[wikidata-populate-site-tables]: Triggered 'refresh' from 1 events
==> default: Notice: /Stage[main]/Mediawiki/Mediawiki::User[admin_user_in_steward_suppress_on_wiki]/Mediawiki::Maintenance[mediawiki_user_Admin_wiki]/Exec[mediawiki_user_Admin_wiki]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki/Mediawiki::User[admin_user_in_steward_suppress_on_wiki]/Mediawiki::Maintenance[mediawiki_user_Admin_wiki]/Exec[mediawiki_user_Admin_wiki]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki/Mediawiki::User[admin_user_in_steward_suppress_on_wiki]/Mediawiki::Maintenance[mediawiki_user_Admin_wiki_steward,suppress]/Exec[mediawiki_user_Admin_wiki_steward,suppress]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki/Mediawiki::User[admin_user_in_steward_suppress_on_wiki]/Mediawiki::Maintenance[mediawiki_user_Admin_wiki_steward,suppress]/Exec[mediawiki_user_Admin_wiki_steward,suppress]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki/Mediawiki::Import::Text[Main_Page]/Mediawiki::Maintenance[add page devwiki/Main_Page]/Exec[add page devwiki/Main_Page]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki/Mediawiki::Import::Text[Main_Page]/Mediawiki::Maintenance[add page devwiki/Main_Page]/Exec[add page devwiki/Main_Page]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki/Mediawiki::Import::Text[Template:Main_Page]/Mediawiki::Maintenance[add page devwiki/Template:Main_Page]/Exec[add page devwiki/Template:Main_Page]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki/Mediawiki::Import::Text[Template:Main_Page]/Mediawiki::Maintenance[add page devwiki/Template:Main_Page]/Exec[add page devwiki/Template:Main_Page]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/File[/etc/default/jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/File[/etc/default/jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/File[/etc/jobrunner.json]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/File[/etc/jobrunner.json]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/File[/etc/logrotate.d/mediawiki_jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/File[/etc/logrotate.d/mediawiki_jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/File[/etc/logrotate.d/mediawiki_jobchron]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/File[/etc/logrotate.d/mediawiki_jobchron]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Git::Clone[mediawiki/services/jobrunner]/File[/vagrant/srv/jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Git::Clone[mediawiki/services/jobrunner]/File[/vagrant/srv/jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Git::Clone[mediawiki/services/jobrunner]/Exec[git_clone_mediawiki/services/jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Git::Clone[mediawiki/services/jobrunner]/Exec[git_clone_mediawiki/services/jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Service::Gitupdate[jobrunner]/File[/etc/mw-vagrant/services/jobrunner.conf]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Service::Gitupdate[jobrunner]/File[/etc/mw-vagrant/services/jobrunner.conf]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Service::Gitupdate[jobchron]/File[/etc/mw-vagrant/services/jobchron.conf]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Service::Gitupdate[jobchron]/File[/etc/mw-vagrant/services/jobchron.conf]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/File[/lib/systemd/system/jobrunner.service]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/File[/lib/systemd/system/jobrunner.service]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/Exec[systemd reload for jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/Exec[systemd reload for jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/Service[jobrunner]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobrunner]/Service[jobrunner]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/File[/lib/systemd/system/jobchron.service]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/File[/lib/systemd/system/jobchron.service]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/Exec[systemd reload for jobchron]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/Exec[systemd reload for jobchron]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/Service[jobchron]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Mediawiki::Jobrunner/Systemd::Service[jobchron]/Service[jobchron]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[Wiki:Main Page]/Mediawiki::Maintenance[add page wikidata/Wiki:Main Page]/Exec[add page wikidata/Wiki:Main Page]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[Wiki:Main Page]/Mediawiki::Maintenance[add page wikidata/Wiki:Main Page]/Exec[add page wikidata/Wiki:Main Page]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[Wiki:Main Page]/Mediawiki::Maintenance[add page wikidata/Wiki:Main Page]/Exec[add page wikidata/Wiki:Main Page]: Triggered 'refresh' from 1 events
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[MediaWiki:Mainpage]/Mediawiki::Maintenance[add page wikidata/MediaWiki:Mainpage]/Exec[add page wikidata/MediaWiki:Mainpage]: Dependency Exec[composer-install--vagrant-mediawiki-extensions-WikidataBuildResources] has failures: true
==> default: Warning: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[MediaWiki:Mainpage]/Mediawiki::Maintenance[add page wikidata/MediaWiki:Mainpage]/Exec[add page wikidata/MediaWiki:Mainpage]: Skipping because of failed dependencies
==> default: Notice: /Stage[main]/Role::Wikidata/Mediawiki::Import::Text[MediaWiki:Mainpage]/Mediawiki::Maintenance[add page wikidata/MediaWiki:Mainpage]/Exec[add page wikidata/MediaWiki:Mainpage]: Triggered 'refresh' from 1 events
==> default: Notice: Finished catalog run in 990.96 seconds
The SSH command responded with a non-zero exit status. Vagrant
assumes that this means the command failed. The output for this command
should be in the log above. Please read the output to determine what
went wrong.