from saleshub

gistfile1.txt

[Wed, 21 Dec 2011 22:55:53 +0100] INFO: *** Chef 0.10.4 ***
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Building node object for enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Extracting run list from JSON attributes provided on command line
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Setting the run_list to ["enterprise-configure"] from JSON
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Applying attributes from json file
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Platform is ubuntu version 11.10
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Run List is [recipe[enterprise-configure]]
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Run List expands to [enterprise-configure]
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Starting Chef Run for enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: No chefignore file found at /data/enterprise/cookbooks/chefignore no files will be ignored
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook mysql's library file: /data/enterprise/cookbooks/mysql/libraries/database.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-core's library file: /data/enterprise/cookbooks/gh-core/libraries/enterprise_log.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook mysql's providers from /data/enterprise/cookbooks/mysql/providers/database.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loaded contents of /data/enterprise/cookbooks/mysql/providers/database.rb into a provider named mysql_database defined in Chef::Provider::MysqlDatabase
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook apt's providers from /data/enterprise/cookbooks/apt/providers/repository.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loaded contents of /data/enterprise/cookbooks/apt/providers/repository.rb into a provider named apt_repository defined in Chef::Provider::AptRepository
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook god's providers from /data/enterprise/cookbooks/god/providers/service.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loaded contents of /data/enterprise/cookbooks/god/providers/service.rb into a provider named god_service defined in Chef::Provider::GodService
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook mysql's resources from /data/enterprise/cookbooks/mysql/resources/database.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loaded contents of /data/enterprise/cookbooks/mysql/resources/database.rb into a resource named mysql_database defined in Chef::Resource::MysqlDatabase
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook apt's resources from /data/enterprise/cookbooks/apt/resources/repository.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loaded contents of /data/enterprise/cookbooks/apt/resources/repository.rb into a resource named apt_repository defined in Chef::Resource::AptRepository
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook git-daemon's attribute file /data/enterprise/cookbooks/git-daemon/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Attribute gh-core
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook solr's attribute file /data/enterprise/cookbooks/solr/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook mysql's attribute file /data/enterprise/cookbooks/mysql/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-core's attribute file /data/enterprise/cookbooks/gh-core/attributes/gems.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-core's attribute file /data/enterprise/cookbooks/gh-core/attributes/github.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-core's attribute file /data/enterprise/cookbooks/gh-core/attributes/packages.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-core's attribute file /data/enterprise/cookbooks/gh-core/attributes/python_packages.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-core's attribute file /data/enterprise/cookbooks/gh-core/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook github's attribute file /data/enterprise/cookbooks/github/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Attribute gh-core::github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook unicorn's attribute file /data/enterprise/cookbooks/unicorn/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook nginx's attribute file /data/enterprise/cookbooks/nginx/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook resque's attribute file /data/enterprise/cookbooks/resque/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Attribute github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core::github, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook network's attribute file /data/enterprise/cookbooks/network/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook memcached's attribute file /data/enterprise/cookbooks/memcached/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook god's attribute file /data/enterprise/cookbooks/god/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook gh-storage's attribute file /data/enterprise/cookbooks/gh-storage/attributes/device.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook approx's attribute file /data/enterprise/cookbooks/approx/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook bundler's attribute file /data/enterprise/cookbooks/bundler/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook ruby's attribute file /data/enterprise/cookbooks/ruby/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook enterprise-manage's attribute file /data/enterprise/cookbooks/enterprise-manage/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook cloud-init's attribute file /data/enterprise/cookbooks/cloud-init/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook virtual-box's attribute file /data/enterprise/cookbooks/virtual-box/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook redis's attribute file /data/enterprise/cookbooks/redis/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook openssh's attribute file /data/enterprise/cookbooks/openssh/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Node enterprise-11-10-28-i386 loading cookbook github-services's attribute file /data/enterprise/cookbooks/github-services/attributes/default.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading attribute file gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook mysql's definitions from /data/enterprise/cookbooks/mysql/definitions/mysql_encoding_fix.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-core's definitions from /data/enterprise/cookbooks/gh-core/definitions/app_layout.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-core's definitions from /data/enterprise/cookbooks/gh-core/definitions/rack_app.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-core's definitions from /data/enterprise/cookbooks/gh-core/definitions/link_config.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-core's definitions from /data/enterprise/cookbooks/gh-core/definitions/environment_file.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook unicorn's definitions from /data/enterprise/cookbooks/unicorn/definitions/unicorn_site.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook nginx's definitions from /data/enterprise/cookbooks/nginx/definitions/nginx_site.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook thin's definitions from /data/enterprise/cookbooks/thin/definitions/thin_site.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook resque's definitions from /data/enterprise/cookbooks/resque/definitions/resque_work.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook god's definitions from /data/enterprise/cookbooks/god/definitions/god_monitor.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook god's definitions from /data/enterprise/cookbooks/god/definitions/god_task.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook god's definitions from /data/enterprise/cookbooks/god/definitions/god.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-storage's definitions from /data/enterprise/cookbooks/gh-storage/definitions/rootfs_storage.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-storage's definitions from /data/enterprise/cookbooks/gh-storage/definitions/repo_storage.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook gh-storage's definitions from /data/enterprise/cookbooks/gh-storage/definitions/device_storage.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading cookbook bundler's definitions from /data/enterprise/cookbooks/bundler/definitions/bundle.rb
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe enterprise-configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook enterprise-configure
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe gh-support via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook gh-support
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe enterprise-configure::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook enterprise-configure
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe approx via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook approx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe approx::import via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe import in cookbook approx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Importing System Packages] to the state of the prior enterprise_log[Importing System Packages]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe apt via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook apt
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe apt::setup via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe setup in cookbook apt
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe gh-core via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook gh-core
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe gh-core::user via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe user in cookbook gh-core
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting directory[/root/.ssh] to the state of the prior directory[/root/.ssh]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe gh-core::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook gh-core
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe network via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook network
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe network::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook network
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe gh-storage via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook gh-storage
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Configuring Repository Storage] to the state of the prior enterprise_log[Configuring Repository Storage]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe enterprise-manage via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook enterprise-manage
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe enterprise-manage::environment via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe environment in cookbook enterprise-manage
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe bundler via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook bundler
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe ruby via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook ruby
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe ruby::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook ruby
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading apt, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe bundler::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook bundler
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe god via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook god
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading ruby, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe god::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook god
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe god::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook god
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe god::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook god
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting execute[god load enterprise-manage-unicorn] to the state of the prior execute[god load enterprise-manage-unicorn]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe nginx via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook nginx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe nginx::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook nginx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading apt, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe nginx::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook nginx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe nginx::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook nginx
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Configuring the Enterprise Management Console Application] to the state of the prior enterprise_log[Configuring the Enterprise Management Console Application]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe mysql via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook mysql
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe mysql::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook mysql
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe mysql::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook mysql
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading apt, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe mysql::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook mysql
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe openssh via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook openssh
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading mysql, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe openssh::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook openssh
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe openssh::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook openssh
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe openssh::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook openssh
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::database via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe database in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Configuring the GitHub Database] to the state of the prior enterprise_log[Configuring the GitHub Database]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::ssl via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe ssl in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::environment via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe environment in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::app via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe app in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting cookbook_file[/tmp/ssh-wrapper.sh] to the state of the prior cookbook_file[/tmp/ssh-wrapper.sh]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting directory[/data/github/shared/env.d] to the state of the prior directory[/data/github/shared/env.d]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading bundler, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting execute[god load github-unicorn] to the state of the prior execute[god load github-unicorn]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading nginx, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Installing the GitHub Enterprise Application] to the state of the prior enterprise_log[Installing the GitHub Enterprise Application]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::resque via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe resque in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::gitauth via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe gitauth in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting execute[god load gitauth-unicorn] to the state of the prior execute[god load gitauth-unicorn]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting execute[god load gitauth-unicorn] to the state of the prior execute[god load gitauth-unicorn]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::git-proxy via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe git-proxy in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe git-daemon via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook git-daemon
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe git-daemon::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook git-daemon
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe git-daemon::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook git-daemon
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::git-http-server via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe git-http-server in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github::solr via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe solr in cookbook github
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe solr via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook solr
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe java via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook java
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe java::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook java
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading apt, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe solr::configure via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe configure in cookbook solr
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe solr::install via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe install in cookbook solr
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe solr::start via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe start in cookbook solr
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github-services via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe default in cookbook github-services
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading gh-core, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github-services::config via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe config in cookbook github-services
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading Recipe github-services::app via include_recipe
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Found recipe app in cookbook github-services
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting cookbook_file[/tmp/ssh-wrapper.sh] to the state of the prior cookbook_file[/tmp/ssh-wrapper.sh]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting directory[/data/github-services/shared/config] to the state of the prior directory[/data/github-services/shared/config]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading bundler, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading god, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting execute[god load github-services-thin] to the state of the prior execute[god load github-services-thin]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading nginx, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Setting enterprise_log[Installing the GitHub Services Application] to the state of the prior enterprise_log[Installing the GitHub Services Application]
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: I am not loading git-daemon, because I have already seen it.
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Loading from cookbook_path: /data/enterprise/cookbooks
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Converging node enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Processing enterprise_log[Starting Configuration Scripts] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Processing enterprise_log[Starting Configuration Scripts] action info (enterprise-configure::default line 1)
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Processing directory[/root/.ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Processing directory[/root/.ssh] action create (gh-support::default line 1)
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: directory[/root/.ssh] mode changed to 755
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Processing file[/root/.ssh/authorized_keys] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Processing file[/root/.ssh/authorized_keys] action create (gh-support::default line 7)
[Wed, 21 Dec 2011 22:55:54 +0100] DEBUG: Processing cookbook_file[/usr/sbin/enterprise-configure] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:54 +0100] INFO: Processing cookbook_file[/usr/sbin/enterprise-configure] action create (enterprise-configure::configure line 1)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing cookbook_file[/etc/init/enterprise-configure.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing cookbook_file[/etc/init/enterprise-configure.conf] action create (enterprise-configure::configure line 7)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing cookbook_file[/etc/approx/approx.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing cookbook_file[/etc/approx/approx.conf] action create (approx::default line 1)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing execute[update Packages.gz] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing execute[update Packages.gz] action run (approx::import line 1)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Skipping execute[update Packages.gz] due to only_if
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing enterprise_log[Importing System Packages] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing enterprise_log[Importing System Packages] action start (approx::import line 11)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing enterprise_log[Importing System Packages] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing enterprise_log[Importing System Packages] action finish (approx::import line 19)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing cookbook_file[/usr/sbin/policy-rc.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing cookbook_file[/usr/sbin/policy-rc.d] action create (apt::setup line 3)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing cookbook_file[/etc/dpkg/dpkg.cfg] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing cookbook_file[/etc/dpkg/dpkg.cfg] action create (apt::setup line 9)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing cookbook_file[/etc/apt/apt.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing cookbook_file[/etc/apt/apt.conf] action create (apt::setup line 15)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing directory[/etc/apt/sources.list.d/] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing directory[/etc/apt/sources.list.d/] action delete (apt::setup line 21)
[Wed, 21 Dec 2011 22:55:55 +0100] DEBUG: Processing execute[apt-get update] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: Processing execute[apt-get update] action run (apt::default line 3)
[Wed, 21 Dec 2011 22:55:55 +0100] INFO: execute[apt-get update] sh(apt-get update)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[apt-get update] ran successfully
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing execute[remove root user password] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing execute[remove root user password] action run (gh-core::user line 1)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[remove root user password] sh(passwd -l root)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[remove root user password] ran successfully
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing group[git] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing group[git] action create (gh-core::user line 5)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing user[git] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing user[git] action create (gh-core::user line 9)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/home/git/.ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/home/git/.ssh] action create (gh-core::user line 17)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/root/.ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/root/.ssh] action create (gh-core::user line 23)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: directory[/root/.ssh] mode changed to 700
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/data] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/data] action create (gh-core::configure line 1)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/var/run] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/var/run] action create (gh-core::configure line 7)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: directory[/var/run] mode changed to 1777
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/etc/github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/etc/github] action create (gh-core::configure line 13)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing file[/etc/init/firstboot-configure.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing file[/etc/init/firstboot-configure.conf] action delete (gh-core::configure line 19)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Skipping file[/etc/init/firstboot-configure.conf] due to only_if
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing file[/usr/sbin/firstboot-configure] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing file[/usr/sbin/firstboot-configure] action delete (gh-core::configure line 25)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Skipping file[/usr/sbin/firstboot-configure] due to only_if
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/etc/init/boot-configure.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/etc/init/boot-configure.conf] action create (gh-core::configure line 31)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/usr/sbin/get-ip-address] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/usr/sbin/get-ip-address] action create (gh-core::configure line 37)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/usr/sbin/boot-configure] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/usr/sbin/boot-configure] action create (gh-core::configure line 43)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/etc/init/tty1.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/etc/init/tty1.conf] action create (gh-core::configure line 49)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing file[/etc/issue] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing file[/etc/issue] action delete (gh-core::configure line 55)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Skipping file[/etc/issue] due to only_if
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/usr/local/bin/github-env] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/usr/local/bin/github-env] action create (gh-core::configure line 61)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/usr/local/bin/github-console] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/usr/local/bin/github-console] action create (gh-core::configure line 67)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing gem_package[highline] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing gem_package[highline] action install (gh-core::default line 5)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: gem_package[highline] found installed gem highline version 1.6.8 matching highline (= 1.6.8, runtime)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: gem_package[highline] is already installed - nothing to do
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing gem_package[enterprise-scripts] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing gem_package[enterprise-scripts] action install (gh-core::default line 5)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: gem_package[enterprise-scripts] found installed gem enterprise-scripts version 0.1.2 matching enterprise-scripts (= 0.1.2, runtime)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: gem_package[enterprise-scripts] is already installed - nothing to do
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/etc/network/interfaces.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/etc/network/interfaces.d] action create (network::configure line 1)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/etc/network/interfaces.d/dhcp] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/etc/network/interfaces.d/dhcp] action create (network::configure line 6)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/etc/network/interfaces] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/etc/network/interfaces] action create (network::configure line 12)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing file[/usr/local/sbin/network-map] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing file[/usr/local/sbin/network-map] action create (network::configure line 18)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing enterprise_log[Configuring Repository Storage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing enterprise_log[Configuring Repository Storage] action start (gh-storage::default line 3)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/data/repositories] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/data/repositories] action create (gh-storage::default line 3)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing execute[chown /data/repositories] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing execute[chown /data/repositories] action run (gh-storage::default line 14)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[chown /data/repositories] sh(chown git:git /data/repositories)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[chown /data/repositories] ran successfully
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing enterprise_log[Configuring Repository Storage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing enterprise_log[Configuring Repository Storage] action finish (gh-storage::default line 18)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing file[/data/enterprise-manage/shared/env.d/00-rack-session.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing file[/data/enterprise-manage/shared/env.d/00-rack-session.sh] action create (enterprise-manage::environment line 8)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Skipping file[/data/enterprise-manage/shared/env.d/00-rack-session.sh] due to not_if
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing enterprise_log[Configuring the Enterprise Management Console Application] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing enterprise_log[Configuring the Enterprise Management Console Application] action start (enterprise-manage::default line 3)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing directory[/data/enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing directory[/data/enterprise-manage] action create (enterprise-manage::default line 47)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing cookbook_file[/tmp/ssh-wrapper.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing cookbook_file[/tmp/ssh-wrapper.sh] action create (enterprise-manage::default line 55)
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: File /tmp/ssh-wrapper.sh does not exist, so there is no checksum to generate
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: cookbook_file[/tmp/ssh-wrapper.sh] has new contents
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: cookbook_file[/tmp/ssh-wrapper.sh] staging /data/enterprise/cookbooks/gh-core/files/default/ssh-wrapper.sh to /tmp/ssh-wrapper.sh20111221-8284-8u5g2f-0
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: cookbook_file[/tmp/ssh-wrapper.sh] mode changed to 755
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: cookbook_file[/tmp/ssh-wrapper.sh] created file /tmp/ssh-wrapper.sh
[Wed, 21 Dec 2011 22:55:56 +0100] DEBUG: Processing execute[dpkg -i /data/enterprise/code_debs/enterprise-manage.deb] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: Processing execute[dpkg -i /data/enterprise/code_debs/enterprise-manage.deb] action run (enterprise-manage::default line 64)
[Wed, 21 Dec 2011 22:55:56 +0100] INFO: execute[dpkg -i /data/enterprise/code_debs/enterprise-manage.deb] sh(dpkg -i /data/enterprise/code_debs/enterprise-manage.deb)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: execute[dpkg -i /data/enterprise/code_debs/enterprise-manage.deb] ran successfully
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/var/log/enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/var/log/enterprise-manage] action create (enterprise-manage::default line 34)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/var/run/enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/var/run/enterprise-manage] action create (enterprise-manage::default line 34)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/shared] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/shared] action create (enterprise-manage::default line 45)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/shared/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/shared/log] action create (enterprise-manage::default line 53)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/shared/pids] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/shared/pids] action create (enterprise-manage::default line 60)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/shared/sockets] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/shared/sockets] action create (enterprise-manage::default line 67)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/shared/gems] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/shared/gems] action create (enterprise-manage::default line 74)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/shared/config] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/shared/config] action create (enterprise-manage::default line 80)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/shared/env.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/shared/env.d] action create (enterprise-manage::default line 86)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/shared/script] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/shared/script] action create (enterprise-manage::default line 94)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing template[/data/enterprise-manage/shared/env.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing template[/data/enterprise-manage/shared/env.sh] action create (enterprise-manage::default line 104)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Current content's checksum:  cc367ef3a259e5f3d830844b78af54cfe73a1f325c3762052f0959a8b5406897
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Rendered content's checksum: cc367ef3a259e5f3d830844b78af54cfe73a1f325c3762052f0959a8b5406897
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: template[/data/enterprise-manage/shared/env.sh] content has not changed.
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/stage/tmp] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/stage/tmp] action create (enterprise-manage::default line 115)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: directory[/data/enterprise-manage/stage/tmp] created directory /data/enterprise-manage/stage/tmp
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: directory[/data/enterprise-manage/stage/tmp] owner changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: directory[/data/enterprise-manage/stage/tmp] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: directory[/data/enterprise-manage/stage/tmp] mode changed to 755
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/stage/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/stage/log] action delete (enterprise-manage::default line 123)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Executing test -d /data/enterprise-manage/stage/log
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: ---- Begin output of test -d /data/enterprise-manage/stage/log ----
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: ---- End output of test -d /data/enterprise-manage/stage/log ----
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Ran test -d /data/enterprise-manage/stage/log returned 1
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Skipping directory[/data/enterprise-manage/stage/log] due to only_if
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/stage/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/stage/log] action create (enterprise-manage::default line 131)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: link[/data/enterprise-manage/stage/log] created symbolic link from /data/enterprise-manage/shared/log -> /data/enterprise-manage/stage/log
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/log] created
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/log] owner changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/log] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/stage/tmp/pids] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/stage/tmp/pids] action create (enterprise-manage::default line 138)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: link[/data/enterprise-manage/stage/tmp/pids] created symbolic link from /data/enterprise-manage/shared/pids -> /data/enterprise-manage/stage/tmp/pids
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/pids] created
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/pids] owner changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/pids] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/stage/tmp/sockets] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/stage/tmp/sockets] action create (enterprise-manage::default line 145)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: link[/data/enterprise-manage/stage/tmp/sockets] created symbolic link from /data/enterprise-manage/shared/sockets -> /data/enterprise-manage/stage/tmp/sockets
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/sockets] created
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/sockets] owner changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/tmp/sockets] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing directory[/data/enterprise-manage/stage/vendor] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing directory[/data/enterprise-manage/stage/vendor] action create (enterprise-manage::default line 152)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: directory[/data/enterprise-manage/stage/vendor] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing link[/data/enterprise-manage/stage/vendor/gems] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing link[/data/enterprise-manage/stage/vendor/gems] action create (enterprise-manage::default line 160)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: link[/data/enterprise-manage/stage/vendor/gems] created symbolic link from /data/enterprise-manage/shared/gems -> /data/enterprise-manage/stage/vendor/gems
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/vendor/gems] created
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/vendor/gems] owner changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: link[/data/enterprise-manage/stage/vendor/gems] group changed to 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing execute[link files in /data/enterprise-manage/shared/config to /data/enterprise-manage/stage/config] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing execute[link files in /data/enterprise-manage/shared/config to /data/enterprise-manage/stage/config] action run (enterprise-manage::default line 6)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: execute[link files in /data/enterprise-manage/shared/config to /data/enterprise-manage/stage/config] sh(      for file in $(ls /data/enterprise-manage/shared/config) ; do
        ln -sf /data/enterprise-manage/shared/config/$file /data/enterprise-manage/stage/config
      done
)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: execute[link files in /data/enterprise-manage/shared/config to /data/enterprise-manage/stage/config] ran successfully
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing file[/data/enterprise-manage/shared/env.d/00-rack.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing file[/data/enterprise-manage/shared/env.d/00-rack.sh] action create (enterprise-manage::default line 8)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing file[/data/enterprise-manage/shared/env.d/90-enterprise-manage.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing file[/data/enterprise-manage/shared/env.d/90-enterprise-manage.sh] action create (enterprise-manage::default line 8)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing execute[chown -R root:root /data/enterprise-manage/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing execute[chown -R root:root /data/enterprise-manage/stage] action run (enterprise-manage::default line 112)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: execute[chown -R root:root /data/enterprise-manage/stage] sh(chown -R root:root /data/enterprise-manage/stage)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: execute[chown -R root:root /data/enterprise-manage/stage] ran successfully
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[buildessential] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[buildessential] action upgrade (ruby::install line 4)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[buildessential] checking package status for buildessential
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy buildessential)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[buildessential] is at the latest version - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[ruby-dev] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[ruby-dev] action upgrade (ruby::install line 4)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[ruby-dev] checking package status for ruby-dev
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy ruby-dev)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[ruby-dev] current version is 4.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[ruby-dev] candidate version is 4.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[ruby-dev] is at the latest version - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[libruby] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[libruby] action upgrade (ruby::install line 4)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libruby] checking package status for libruby
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy libruby)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libruby] current version is 4.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libruby] candidate version is 4.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libruby] is at the latest version - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[libshadow-ruby1.8] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[libshadow-ruby1.8] action upgrade (ruby::install line 4)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libshadow-ruby1.8] checking package status for libshadow-ruby1.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy libshadow-ruby1.8)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libshadow-ruby1.8] current version is 1.4.1-8build1
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libshadow-ruby1.8] candidate version is 1.4.1-8build1
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[libshadow-ruby1.8] is at the latest version - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[rubygems1.8] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[rubygems1.8] action install (ruby::install line 9)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems1.8] checking package status for rubygems1.8
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy rubygems1.8)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems1.8] current version is 1.3.7-3
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems1.8] candidate version is 1.3.7-3
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems1.8] is already installed - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing package[rubygems] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing package[rubygems] action install (ruby::install line 15)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems] checking package status for rubygems
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: sh(apt-cache policy rubygems)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems] current version is 1.3.7-3
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems] candidate version is 1.3.7-3
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: package[rubygems] is already installed - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing execute[add rubygem's bin directory to path for root] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing execute[add rubygem's bin directory to path for root] action run (ruby::install line 21)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Executing grep -q '/var/lib/gems/1.8/bin' /etc/environment
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: ---- Begin output of grep -q '/var/lib/gems/1.8/bin' /etc/environment ----
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: ---- End output of grep -q '/var/lib/gems/1.8/bin' /etc/environment ----
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Ran grep -q '/var/lib/gems/1.8/bin' /etc/environment returned 0
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Skipping execute[add rubygem's bin directory to path for root] due to not_if
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing cookbook_file[/etc/profile.d/rubygems_path.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing cookbook_file[/etc/profile.d/rubygems_path.sh] action create (ruby::install line 27)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing gem_package[bundler] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing gem_package[bundler] action install (bundler::install line 1)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: gem_package[bundler] found installed gem bundler version 1.0.13 matching bundler (= 1.0.13, runtime)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: gem_package[bundler] is already installed - nothing to do
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing script[bootstrap /data/enterprise-manage/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing script[bootstrap /data/enterprise-manage/stage] action run (enterprise-manage::default line 8)
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Skipping script[bootstrap /data/enterprise-manage/stage] due to only_if
[Wed, 21 Dec 2011 22:56:00 +0100] DEBUG: Processing script[bundle /data/enterprise-manage/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: Processing script[bundle /data/enterprise-manage/stage] action run (enterprise-manage::default line 25)
[Wed, 21 Dec 2011 22:56:00 +0100] INFO: script[bundle /data/enterprise-manage/stage] sh("bash" --login "/tmp/chef-script20111221-8284-16wyj8-0")
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: script[bundle /data/enterprise-manage/stage] ran successfully
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing template[/data/enterprise-manage/shared/script/enterprise-manage.pre-start.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing template[/data/enterprise-manage/shared/script/enterprise-manage.pre-start.sh] action create (enterprise-manage::default line 37)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Current content's checksum:  1204181db8242a91e6bd75007848c715ff2fd10a2020f8a6ada5f55778569b1d
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Rendered content's checksum: 1204181db8242a91e6bd75007848c715ff2fd10a2020f8a6ada5f55778569b1d
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: template[/data/enterprise-manage/shared/script/enterprise-manage.pre-start.sh] content has not changed.
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing template[/data/enterprise-manage/shared/script/enterprise-manage.start.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing template[/data/enterprise-manage/shared/script/enterprise-manage.start.sh] action create (enterprise-manage::default line 51)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Current content's checksum:  02d2653c9c81a2c1640e9e94720c3e69ded2d1e39ce95300e21846ebd2303cb4
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Rendered content's checksum: 02d2653c9c81a2c1640e9e94720c3e69ded2d1e39ce95300e21846ebd2303cb4
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: template[/data/enterprise-manage/shared/script/enterprise-manage.start.sh] content has not changed.
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing template[/etc/init/enterprise-manage-unicorn.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing template[/etc/init/enterprise-manage-unicorn.conf] action create (enterprise-manage::default line 72)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Current content's checksum:  04b2173edbabfb290466f1d9fcc22d8542603ec583b0c798fd84d4695ef9e192
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Rendered content's checksum: 04b2173edbabfb290466f1d9fcc22d8542603ec583b0c798fd84d4695ef9e192
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: template[/etc/init/enterprise-manage-unicorn.conf] content has not changed.
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing service[enterprise-manage-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing service[enterprise-manage-unicorn] action enable (enterprise-manage::default line 85)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: service[enterprise-manage-unicorn] found /etc/init/enterprise-manage-unicorn.conf
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: service[enterprise-manage-unicorn] enabled: start on runlevel [2345]
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: service[enterprise-manage-unicorn] already enabled - nothing to do
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing gem_package[god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing gem_package[god] action install (god::install line 1)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: gem_package[god] found installed gem god version 0.11.0 matching god (>= 0, runtime)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: gem_package[god] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing execute[symlink god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing execute[symlink god] action run (god::install line 5)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Executing test -h /usr/sbin/god
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: ---- Begin output of test -h /usr/sbin/god ----
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: ---- End output of test -h /usr/sbin/god ----
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Ran test -h /usr/sbin/god returned 0
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Skipping execute[symlink god] due to not_if
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing directory[/etc/god.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing directory[/etc/god.d] action create (god::configure line 1)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing directory[/etc/god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing directory[/etc/god] action create (god::configure line 7)
[Wed, 21 Dec 2011 22:57:38 +0100] DEBUG: Processing template[/etc/god/master.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:38 +0100] INFO: Processing template[/etc/god/master.god] action create (god::configure line 13)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Current content's checksum:  f8a69cdf38128e973954841ff90db8e13a68c49df094e69651b54c08b8ee34b0
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Rendered content's checksum: f8a69cdf38128e973954841ff90db8e13a68c49df094e69651b54c08b8ee34b0
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: template[/etc/god/master.god] content has not changed.
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing template[/etc/init/god.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing template[/etc/init/god.conf] action create (god::configure line 21)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Current content's checksum:  4bb7308c8fb3b6b800f00a8400177ed145a80f1fdd5348d936e76a83d7c637aa
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Rendered content's checksum: 4bb7308c8fb3b6b800f00a8400177ed145a80f1fdd5348d936e76a83d7c637aa
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: template[/etc/init/god.conf] content has not changed.
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing cookbook_file[/usr/sbin/god-post-start.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing cookbook_file[/usr/sbin/god-post-start.sh] action create (god::configure line 29)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing service[god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing service[god] action start (god::start line 1)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: service[god] found /etc/init/god.conf
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: service[god] enabled: start on runlevel [345]
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: service[god] already running - nothing to do
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing ruby_block[wait for god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing ruby_block[wait for god] action nothing (god::start line 7)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Executing god status
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: ---- Begin output of god status ----
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: STDOUT: memcached: up
mysql: up
nginx: up
redis-server: up
ssh: up
enterprise-manage:
  enterprise-manage-unicorn: up
github:
  git-daemon: up
  git-http-proxy: up
  git-http-server: up
  git-proxy: up
  gitauth-unicorn: up
  github-resque-1: up
  github-resque-2: up
  github-resque-3: up
  github-resque-4: up
  github-unicorn: up
  solr: up
github-services:
  github-services-thin: up
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: ---- End output of god status ----
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Ran god status returned 0
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Skipping ruby_block[wait for god] due to not_if
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing ruby_block[wait for enterprise-manage-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing ruby_block[wait for enterprise-manage-unicorn] action nothing (enterprise-manage::default line 21)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Executing god status enterprise-manage-unicorn | grep -q 'up'
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: ---- Begin output of god status enterprise-manage-unicorn | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: ---- End output of god status enterprise-manage-unicorn | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Ran god status enterprise-manage-unicorn | grep -q 'up' returned 0
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Skipping ruby_block[wait for enterprise-manage-unicorn] due to not_if
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing execute[god load enterprise-manage-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing execute[god load enterprise-manage-unicorn] action nothing (enterprise-manage::default line 37)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Doing nothing for execute[god load enterprise-manage-unicorn]
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing template[/etc/god.d/enterprise-manage-unicorn.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing template[/etc/god.d/enterprise-manage-unicorn.god] action create (enterprise-manage::default line 45)
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Current content's checksum:  44434f49d7d07c027d13653e3d806a4dfbb02536e28ca0ea1ade1ac4ed4448d1
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Rendered content's checksum: 44434f49d7d07c027d13653e3d806a4dfbb02536e28ca0ea1ade1ac4ed4448d1
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: template[/etc/god.d/enterprise-manage-unicorn.god] content has not changed.
[Wed, 21 Dec 2011 22:57:39 +0100] DEBUG: Processing execute[god load enterprise-manage-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: Processing execute[god load enterprise-manage-unicorn] action run (enterprise-manage::default line 2)
[Wed, 21 Dec 2011 22:57:39 +0100] INFO: execute[god load enterprise-manage-unicorn] sh(god load /etc/god.d/enterprise-manage-unicorn.god)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: execute[god load enterprise-manage-unicorn] ran successfully
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing execute[god restart enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing execute[god restart enterprise-manage] action nothing (enterprise-manage::default line 160)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Doing nothing for execute[god restart enterprise-manage]
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing execute[rm -rf /data/enterprise-manage/current ; mv -f /data/enterprise-manage/stage /data/enterprise-manage/current] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing execute[rm -rf /data/enterprise-manage/current ; mv -f /data/enterprise-manage/stage /data/enterprise-manage/current] action run (enterprise-manage::default line 165)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: execute[rm -rf /data/enterprise-manage/current ; mv -f /data/enterprise-manage/stage /data/enterprise-manage/current] sh(rm -rf /data/enterprise-manage/current ; mv -f /data/enterprise-manage/stage /data/enterprise-manage/current)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: execute[rm -rf /data/enterprise-manage/current ; mv -f /data/enterprise-manage/stage /data/enterprise-manage/current] ran successfully
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing bash[migrate enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing bash[migrate enterprise-manage] action run (enterprise-manage::default line 169)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Skipping bash[migrate enterprise-manage] due to only_if
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing bash[bundle enterprise-manage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing bash[bundle enterprise-manage] action run (enterprise-manage::default line 181)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Skipping bash[bundle enterprise-manage] due to only_if
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing package[nginx] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing package[nginx] action install (nginx::install line 3)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: package[nginx] checking package status for nginx
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: sh(apt-cache policy nginx)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: package[nginx] current version is 1.0.4+github5
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: package[nginx] candidate version is 1.0.4+github5
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: package[nginx] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing directory[/etc/nginx/sites-enabled] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing directory[/etc/nginx/sites-enabled] action create (nginx::configure line 2)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing directory[/var/log/nginx] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing directory[/var/log/nginx] action create (nginx::configure line 10)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing template[/etc/nginx/nginx.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing template[/etc/nginx/nginx.conf] action create (nginx::configure line 16)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Current content's checksum:  5fa7736b41f575679a1151c68af7b74432aa9508b261788830fddea458e70251
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Rendered content's checksum: 5fa7736b41f575679a1151c68af7b74432aa9508b261788830fddea458e70251
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: template[/etc/nginx/nginx.conf] content has not changed.
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing cookbook_file[/etc/nginx/sites-enabled/default] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing cookbook_file[/etc/nginx/sites-enabled/default] action create (nginx::configure line 26)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing remote_directory[/etc/nginx/common] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing remote_directory[/etc/nginx/common] action create (nginx::configure line 33)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing cookbook_file[/etc/nginx/common/maint_page.conf] action create (dynamically defined)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing cookbook_file[/etc/nginx/common/error_pages.conf] action create (dynamically defined)
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: remote_directory[/etc/nginx/common] created
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing service[nginx] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing service[nginx] action start (nginx::start line 1)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: service[nginx] falling back to process table inspection
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: service[nginx] attempting to match 'nginx' (/nginx/) against process list
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: service[nginx] running: true
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: service[nginx] already running - nothing to do
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Processing ruby_block[wait for nginx] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:40 +0100] INFO: Processing ruby_block[wait for nginx] action nothing (nginx::start line 21)
[Wed, 21 Dec 2011 22:57:40 +0100] DEBUG: Executing god status nginx | grep -q 'up'
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: ---- Begin output of god status nginx | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: ---- End output of god status nginx | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Ran god status nginx | grep -q 'up' returned 0
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Skipping ruby_block[wait for nginx] due to not_if
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing execute[god load nginx] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing execute[god load nginx] action nothing (nginx::start line 37)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Doing nothing for execute[god load nginx]
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/god.d/nginx.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/god.d/nginx.god] action create (nginx::start line 45)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  da00d3437e3cb0577129a436f0af99dd62be56ceeebbec71d56e6d8343b73efb
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: da00d3437e3cb0577129a436f0af99dd62be56ceeebbec71d56e6d8343b73efb
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/god.d/nginx.god] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/nginx/sites-enabled/enterprise-manage.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/nginx/sites-enabled/enterprise-manage.conf] action create (enterprise-manage::default line 13)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  8311c07805fed64d0ca40a3eac156bc6c326baa457b4d6e5757f512df9088199
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: 8311c07805fed64d0ca40a3eac156bc6c326baa457b4d6e5757f512df9088199
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/nginx/sites-enabled/enterprise-manage.conf] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing enterprise_log[Configuring the Enterprise Management Console Application] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing enterprise_log[Configuring the Enterprise Management Console Application] action finish (enterprise-manage::default line 14)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing group[mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing group[mysql] action create (mysql::configure line 1)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing user[mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing user[mysql] action create (mysql::configure line 3)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing directory[/data/mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing directory[/data/mysql] action create (mysql::configure line 9)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing directory[/etc/mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing directory[/etc/mysql] action create (mysql::configure line 15)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/mysql/my.cnf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/mysql/my.cnf] action create (mysql::configure line 21)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  c4923f5ea4b93c3715195eaa57d043cbe9cfa696ef7bff20dd9ab1588d3b3abc
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: c4923f5ea4b93c3715195eaa57d043cbe9cfa696ef7bff20dd9ab1588d3b3abc
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/mysql/my.cnf] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing directory[/var/run/mysqld] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing directory[/var/run/mysqld] action create (mysql::configure line 31)
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: directory[/var/run/mysqld] group changed to 1000
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/init/mysql.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/init/mysql.conf] action create (mysql::configure line 37)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  cc08c10d2c489e0769e2a43b392ea85b49ea487bb7047d74d7b73fb775f05f5d
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: cc08c10d2c489e0769e2a43b392ea85b49ea487bb7047d74d7b73fb775f05f5d
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/init/mysql.conf] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/apparmor.d/usr.sbin.mysqld] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/apparmor.d/usr.sbin.mysqld] action create (mysql::configure line 49)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  48de57cf394ba2f66f50e3134ba5e0de898dfb0142608c2d44792c05647925dc
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: 48de57cf394ba2f66f50e3134ba5e0de898dfb0142608c2d44792c05647925dc
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/apparmor.d/usr.sbin.mysqld] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing package[mysql-server] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing package[mysql-server] action install (mysql::install line 3)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-server] checking package status for mysql-server
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: sh(apt-cache policy mysql-server)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-server] current version is 5.1.58-1ubuntu1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-server] candidate version is 5.1.58-1ubuntu1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-server] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing package[mysql-client] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing package[mysql-client] action install (mysql::install line 9)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-client] checking package status for mysql-client
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: sh(apt-cache policy mysql-client)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-client] current version is 5.1.58-1ubuntu1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-client] candidate version is 5.1.58-1ubuntu1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[mysql-client] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing service[mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing service[mysql] action start (mysql::start line 1)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[mysql] found /etc/init/mysql.conf
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[mysql] enabled: start on (net-device-up
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[mysql] already running - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing ruby_block[wait for mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing ruby_block[wait for mysql] action nothing (mysql::start line 21)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Executing god status mysql | grep -q 'up'
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: ---- Begin output of god status mysql | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: ---- End output of god status mysql | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Ran god status mysql | grep -q 'up' returned 0
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Skipping ruby_block[wait for mysql] due to not_if
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing execute[god load mysql] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing execute[god load mysql] action nothing (mysql::start line 37)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Doing nothing for execute[god load mysql]
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/god.d/mysql.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/god.d/mysql.god] action create (mysql::start line 45)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  23a0b62454d485d3777e11d17cc2de2a470e378a7536a784e02b8c001b178e88
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: 23a0b62454d485d3777e11d17cc2de2a470e378a7536a784e02b8c001b178e88
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/god.d/mysql.god] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing template[/etc/ssh/sshd_config] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing template[/etc/ssh/sshd_config] action create (openssh::configure line 1)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Current content's checksum:  16d6162eb76f62dcad5a265176f9df61e88874d1094e89be7ecf735390079734
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Rendered content's checksum: 16d6162eb76f62dcad5a265176f9df61e88874d1094e89be7ecf735390079734
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: template[/etc/ssh/sshd_config] content has not changed.
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing cookbook_file[/etc/init/ssh.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing cookbook_file[/etc/init/ssh.conf] action create (openssh::configure line 13)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing package[ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing package[ssh] action install (openssh::install line 1)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[ssh] checking package status for ssh
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: sh(apt-cache policy ssh)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[ssh] current version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[ssh] candidate version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[ssh] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing package[openssh-client] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing package[openssh-client] action install (openssh::install line 9)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-client] checking package status for openssh-client
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: sh(apt-cache policy openssh-client)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-client] current version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-client] candidate version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-client] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing package[openssh-server] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing package[openssh-server] action install (openssh::install line 17)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-server] checking package status for openssh-server
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: sh(apt-cache policy openssh-server)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-server] current version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-server] candidate version is 1:5.8p1-1ubuntu3+github1
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: package[openssh-server] is already installed - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing service[ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing service[ssh] action start (openssh::start line 1)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[ssh] found /etc/init/ssh.conf
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[ssh] enabled: start on filesystem or runlevel [2345]
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: service[ssh] already running - nothing to do
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Processing ruby_block[wait for ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:41 +0100] INFO: Processing ruby_block[wait for ssh] action nothing (openssh::start line 21)
[Wed, 21 Dec 2011 22:57:41 +0100] DEBUG: Executing god status ssh | grep -q 'up'
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: ---- Begin output of god status ssh | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: ---- End output of god status ssh | grep -q 'up' ----
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Ran god status ssh | grep -q 'up' returned 0
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping ruby_block[wait for ssh] due to not_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing execute[god load ssh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing execute[god load ssh] action nothing (openssh::start line 37)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Doing nothing for execute[god load ssh]
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing template[/etc/god.d/ssh.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing template[/etc/god.d/ssh.god] action create (openssh::start line 45)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Current content's checksum:  7f15339a5d1ba0eb126dae89c77ba05f3f05fbd86f96197349f6474d19957232
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Rendered content's checksum: 7f15339a5d1ba0eb126dae89c77ba05f3f05fbd86f96197349f6474d19957232
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: template[/etc/god.d/ssh.god] content has not changed.
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing enterprise_log[Configuring the GitHub Database] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing enterprise_log[Configuring the GitHub Database] action start (github::database line 1)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing mysql_database[create github database] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing mysql_database[create github database] action create_db (github::database line 3)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing ruby_block[convert github_enterprise] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing ruby_block[convert github_enterprise] action create (github::database line 4)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Executing echo 'SHOW VARIABLES LIKE "character_set_database";' | mysql github_enterprise| grep 'utf8'
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: ---- Begin output of echo 'SHOW VARIABLES LIKE "character_set_database";' | mysql github_enterprise| grep 'utf8' ----
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: STDOUT: character_set_database	utf8
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: ---- End output of echo 'SHOW VARIABLES LIKE "character_set_database";' | mysql github_enterprise| grep 'utf8' ----
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Ran echo 'SHOW VARIABLES LIKE "character_set_database";' | mysql github_enterprise| grep 'utf8' returned 0
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping ruby_block[convert github_enterprise] due to not_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing mysql_database[create github user] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing mysql_database[create github user] action query (github::database line 13)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing execute[grant github user] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing execute[grant github user] action run (github::database line 19)
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: execute[grant github user] sh(    /usr/bin/mysql --user root --socket /var/run/mysqld/mysqld.sock       --execute "grant all privileges on github_enterprise.*                  to 'github'@'localhost'                  identified by 'github';"
)
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: execute[grant github user] ran successfully
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing enterprise_log[Configuring the GitHub Database] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing enterprise_log[Configuring the GitHub Database] action finish (github::database line 28)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing directory[/etc/ssl] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing directory[/etc/ssl] action create (github::ssl line 1)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/etc/ssl/github_crt] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/etc/ssl/github_crt] action create (github::ssl line 7)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping file[/etc/ssl/github_crt] due to only_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/etc/ssl/github_key] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/etc/ssl/github_key] action create (github::ssl line 17)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping file[/etc/ssl/github_key] due to only_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing directory[/data/github/shared/env.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing directory[/data/github/shared/env.d] action create (github::environment line 1)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-rails-session.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-rails-session.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping file[/data/github/shared/env.d/00-rails-session.sh] due to not_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-solr.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-solr.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-smtp-secret.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-smtp-secret.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Skipping file[/data/github/shared/env.d/00-smtp-secret.sh] due to not_if
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-smtp.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-smtp.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-license.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-license.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: file[/data/github/shared/env.d/00-license.sh] contents updated
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-auth.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-auth.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-ldap.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-ldap.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-pages.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-pages.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-git.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing file[/data/github/shared/env.d/00-git.sh] action create (github::environment line 8)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing enterprise_log[Installing the GitHub Enterprise Application] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing enterprise_log[Installing the GitHub Enterprise Application] action start (github::app line 1)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing directory[/data/github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing directory[/data/github] action create (github::app line 47)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing cookbook_file[/tmp/ssh-wrapper.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing cookbook_file[/tmp/ssh-wrapper.sh] action create (github::app line 55)
[Wed, 21 Dec 2011 22:57:42 +0100] DEBUG: Processing execute[dpkg -i /data/enterprise/code_debs/github.deb] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: Processing execute[dpkg -i /data/enterprise/code_debs/github.deb] action run (github::app line 64)
[Wed, 21 Dec 2011 22:57:42 +0100] INFO: execute[dpkg -i /data/enterprise/code_debs/github.deb] sh(dpkg -i /data/enterprise/code_debs/github.deb)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: execute[dpkg -i /data/enterprise/code_debs/github.deb] ran successfully
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/var/log/github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/var/log/github] action create (github::app line 34)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/var/run/github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/var/run/github] action create (github::app line 34)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/shared] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/shared] action create (github::app line 45)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/shared/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/shared/log] action create (github::app line 53)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/shared/pids] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/shared/pids] action create (github::app line 60)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/shared/sockets] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/shared/sockets] action create (github::app line 67)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/shared/gems] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/shared/gems] action create (github::app line 74)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/shared/config] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/shared/config] action create (github::app line 80)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/shared/env.d] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/shared/env.d] action create (github::app line 86)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/shared/script] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/shared/script] action create (github::app line 94)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing template[/data/github/shared/env.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing template[/data/github/shared/env.sh] action create (github::app line 104)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Current content's checksum:  bdafce229722d7cb9e3adf44543638b29765f85b86d759ef131925a746ed8483
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Rendered content's checksum: bdafce229722d7cb9e3adf44543638b29765f85b86d759ef131925a746ed8483
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: template[/data/github/shared/env.sh] content has not changed.
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/stage/tmp] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/stage/tmp] action create (github::app line 115)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: directory[/data/github/stage/tmp] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/stage/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/stage/log] action delete (github::app line 123)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Executing test -d /data/github/stage/log
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: ---- Begin output of test -d /data/github/stage/log ----
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: ---- End output of test -d /data/github/stage/log ----
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Ran test -d /data/github/stage/log returned 0
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: directory[/data/github/stage/log] deleted /data/github/stage/log recursively
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/stage/log] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/stage/log] action create (github::app line 131)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: link[/data/github/stage/log] created symbolic link from /data/github/shared/log -> /data/github/stage/log
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/log] created
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/log] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/log] group changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/stage/tmp/pids] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/stage/tmp/pids] action create (github::app line 138)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: link[/data/github/stage/tmp/pids] created symbolic link from /data/github/shared/pids -> /data/github/stage/tmp/pids
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/pids] created
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/pids] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/pids] group changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/stage/tmp/sockets] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/stage/tmp/sockets] action create (github::app line 145)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: link[/data/github/stage/tmp/sockets] created symbolic link from /data/github/shared/sockets -> /data/github/stage/tmp/sockets
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/sockets] created
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/sockets] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/tmp/sockets] group changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing directory[/data/github/stage/vendor] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing directory[/data/github/stage/vendor] action create (github::app line 152)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: directory[/data/github/stage/vendor] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing link[/data/github/stage/vendor/gems] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing link[/data/github/stage/vendor/gems] action create (github::app line 160)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: link[/data/github/stage/vendor/gems] created symbolic link from /data/github/shared/gems -> /data/github/stage/vendor/gems
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/vendor/gems] created
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/vendor/gems] owner changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: link[/data/github/stage/vendor/gems] group changed to 500
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing execute[link files in /data/github/shared/config to /data/github/stage/config] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing execute[link files in /data/github/shared/config to /data/github/stage/config] action run (github::app line 6)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: execute[link files in /data/github/shared/config to /data/github/stage/config] sh(      for file in $(ls /data/github/shared/config) ; do
        ln -sf /data/github/shared/config/$file /data/github/stage/config
      done
)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: execute[link files in /data/github/shared/config to /data/github/stage/config] ran successfully
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing file[/data/github/shared/env.d/00-rack.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing file[/data/github/shared/env.d/00-rack.sh] action create (github::app line 8)
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing file[/data/github/shared/env.d/90-github.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing file[/data/github/shared/env.d/90-github.sh] action create (github::app line 8)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: file[/data/github/shared/env.d/90-github.sh] contents updated
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing execute[chown -R git:git /data/github/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing execute[chown -R git:git /data/github/stage] action run (github::app line 112)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: execute[chown -R git:git /data/github/stage] sh(chown -R git:git /data/github/stage)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: execute[chown -R git:git /data/github/stage] ran successfully
[Wed, 21 Dec 2011 22:57:54 +0100] DEBUG: Processing script[bootstrap /data/github/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: Processing script[bootstrap /data/github/stage] action run (github::app line 8)
[Wed, 21 Dec 2011 22:57:54 +0100] INFO: script[bootstrap /data/github/stage] sh("bash" --login "/tmp/chef-script20111221-8284-d33esi-0")
[Wed, 21 Dec 2011 22:58:38 +0100] INFO: script[bootstrap /data/github/stage] ran successfully
[Wed, 21 Dec 2011 22:58:38 +0100] DEBUG: Processing script[bundle /data/github/stage] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:38 +0100] INFO: Processing script[bundle /data/github/stage] action run (github::app line 25)
[Wed, 21 Dec 2011 22:58:38 +0100] DEBUG: Skipping script[bundle /data/github/stage] due to not_if
[Wed, 21 Dec 2011 22:58:38 +0100] DEBUG: Processing template[/data/github/shared/script/github.pre-start.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:38 +0100] INFO: Processing template[/data/github/shared/script/github.pre-start.sh] action create (github::app line 37)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Current content's checksum:  eb1bc05d3d327bc56ceda3c0015266b7c8ae394f0ba44d80b98b4755f39ac02a
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Rendered content's checksum: eb1bc05d3d327bc56ceda3c0015266b7c8ae394f0ba44d80b98b4755f39ac02a
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: template[/data/github/shared/script/github.pre-start.sh] content has not changed.
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing template[/data/github/shared/script/github.start.sh] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing template[/data/github/shared/script/github.start.sh] action create (github::app line 51)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Current content's checksum:  34582bf2292d61b2ba089c3777a46fa66c22b3297a01579829b6d1fa4e0d69a2
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Rendered content's checksum: 34582bf2292d61b2ba089c3777a46fa66c22b3297a01579829b6d1fa4e0d69a2
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: template[/data/github/shared/script/github.start.sh] content has not changed.
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing template[/etc/init/github-unicorn.conf] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing template[/etc/init/github-unicorn.conf] action create (github::app line 72)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Current content's checksum:  3990fbc849b3cb409a20f3fba26bcc9bbc46f71df01a43fe1a3347a889b99e0c
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Rendered content's checksum: 3990fbc849b3cb409a20f3fba26bcc9bbc46f71df01a43fe1a3347a889b99e0c
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: template[/etc/init/github-unicorn.conf] content has not changed.
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing service[github-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing service[github-unicorn] action enable (github::app line 85)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: service[github-unicorn] found /etc/init/github-unicorn.conf
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: service[github-unicorn] enabled: start on runlevel [2345]
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: service[github-unicorn] already enabled - nothing to do
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing ruby_block[wait for github-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing ruby_block[wait for github-unicorn] action nothing (github::app line 21)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Executing god status github-unicorn | grep -q 'up'
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: ---- Begin output of god status github-unicorn | grep -q 'up' ----
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: STDOUT: 
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: STDERR: 
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: ---- End output of god status github-unicorn | grep -q 'up' ----
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Ran god status github-unicorn | grep -q 'up' returned 0
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Skipping ruby_block[wait for github-unicorn] due to not_if
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing execute[god load github-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing execute[god load github-unicorn] action nothing (github::app line 37)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Doing nothing for execute[god load github-unicorn]
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing template[/etc/god.d/github-unicorn.god] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing template[/etc/god.d/github-unicorn.god] action create (github::app line 45)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Current content's checksum:  a15957c52f275e28672a9962b0555568f79a12ba614fee9a6d95e55fc644b283
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Rendered content's checksum: a15957c52f275e28672a9962b0555568f79a12ba614fee9a6d95e55fc644b283
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: template[/etc/god.d/github-unicorn.god] content has not changed.
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing execute[god load github-unicorn] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing execute[god load github-unicorn] action run (github::app line 2)
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: execute[god load github-unicorn] sh(god load /etc/god.d/github-unicorn.god)
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: execute[god load github-unicorn] ran successfully
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing execute[god restart github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing execute[god restart github] action nothing (github::app line 160)
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Doing nothing for execute[god restart github]
[Wed, 21 Dec 2011 22:58:39 +0100] DEBUG: Processing execute[rm -rf /data/github/current ; mv -f /data/github/stage /data/github/current] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: Processing execute[rm -rf /data/github/current ; mv -f /data/github/stage /data/github/current] action run (github::app line 165)
[Wed, 21 Dec 2011 22:58:39 +0100] INFO: execute[rm -rf /data/github/current ; mv -f /data/github/stage /data/github/current] sh(rm -rf /data/github/current ; mv -f /data/github/stage /data/github/current)
[Wed, 21 Dec 2011 22:58:40 +0100] INFO: execute[rm -rf /data/github/current ; mv -f /data/github/stage /data/github/current] ran successfully
[Wed, 21 Dec 2011 22:58:40 +0100] DEBUG: Processing bash[migrate github] on enterprise-11-10-28-i386
[Wed, 21 Dec 2011 22:58:40 +0100] INFO: Processing bash[migrate github] action run (github::app line 169)
[Wed, 21 Dec 2011 22:58:40 +0100] INFO: bash[migrate github] sh("bash"  "/tmp/chef-script20111221-8284-1x90d10-0")
[Wed, 21 Dec 2011 22:58:40 +0100] ERROR: bash[migrate github] (github::app line 169) has had an error
[Wed, 21 Dec 2011 22:58:40 +0100] ERROR: bash[migrate github] (/data/enterprise/cookbooks/gh-core/definitions/rack_app.rb:169:in `from_file') had an error:
bash[migrate github] (github::app line 169) had an error: Expected process to exit with [0], but received '127'
---- Begin output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
STDOUT: 
STDERR: /tmp/chef-script20111221-8284-1x90d10-0: line 2: bin/rake: No such file or directory
---- End output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
Ran "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" returned 127
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:207:in `invalid!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:193:in `error!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/mixin/shell_out.rb:36:in `shell_out!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/execute.rb:58:in `action_run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/script.rb:33:in `action_run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `send'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `run_action'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:45:in `run_action'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `each'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:94:in `execute_each_resource'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:92:in `execute_each_resource'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:76:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:312:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:160:in `run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:192:in `run_application'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `loop'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `run_application'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application.rb:67:in `run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/chef-solo:25
/usr/local/bin/chef-solo:19:in `load'
/usr/local/bin/chef-solo:19
[Wed, 21 Dec 2011 22:58:40 +0100] ERROR: Running exception handlers
[Wed, 21 Dec 2011 22:58:40 +0100] ERROR: Exception handlers complete
[Wed, 21 Dec 2011 22:58:40 +0100] DEBUG: Re-raising exception: Chef::Exceptions::ShellCommandFailed - bash[migrate github] (github::app line 169) had an error: Expected process to exit with [0], but received '127'
---- Begin output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
STDOUT: 
STDERR: /tmp/chef-script20111221-8284-1x90d10-0: line 2: bin/rake: No such file or directory
---- End output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
Ran "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" returned 127
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:207:in `invalid!'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:193:in `error!'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/mixin/shell_out.rb:36:in `shell_out!'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/execute.rb:58:in `action_run'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/script.rb:33:in `action_run'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `send'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `run_action'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:45:in `run_action'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `each'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:94:in `execute_each_resource'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:92:in `execute_each_resource'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:76:in `converge'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:312:in `converge'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:160:in `run'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:192:in `run_application'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `loop'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `run_application'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application.rb:67:in `run'
  /var/lib/gems/1.8/gems/chef-0.10.4/bin/chef-solo:25
  /usr/local/bin/chef-solo:19:in `load'
  /usr/local/bin/chef-solo:19
[Wed, 21 Dec 2011 22:58:40 +0100] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[Wed, 21 Dec 2011 22:58:40 +0100] DEBUG: Chef::Exceptions::ShellCommandFailed: bash[migrate github] (github::app line 169) had an error: Expected process to exit with [0], but received '127'
---- Begin output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
STDOUT: 
STDERR: /tmp/chef-script20111221-8284-1x90d10-0: line 2: bin/rake: No such file or directory
---- End output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
Ran "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" returned 127
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:207:in `invalid!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/shell_out.rb:193:in `error!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/mixin/shell_out.rb:36:in `shell_out!'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/execute.rb:58:in `action_run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/provider/script.rb:33:in `action_run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `send'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource.rb:437:in `run_action'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:45:in `run_action'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `each'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:81:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:94:in `execute_each_resource'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/resource_collection.rb:92:in `execute_each_resource'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/runner.rb:76:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:312:in `converge'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/client.rb:160:in `run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:192:in `run_application'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `loop'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application/solo.rb:183:in `run_application'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/../lib/chef/application.rb:67:in `run'
/var/lib/gems/1.8/gems/chef-0.10.4/bin/chef-solo:25
/usr/local/bin/chef-solo:19:in `load'
/usr/local/bin/chef-solo:19
[Wed, 21 Dec 2011 22:58:40 +0100] FATAL: Chef::Exceptions::ShellCommandFailed: bash[migrate github] (github::app line 169) had an error: Expected process to exit with [0], but received '127'
---- Begin output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
STDOUT: 
STDERR: /tmp/chef-script20111221-8284-1x90d10-0: line 2: bin/rake: No such file or directory
---- End output of "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" ----
Ran "bash"  "/tmp/chef-script20111221-8284-1x90d10-0" returned 127