Initial installation problems on Debian Squeeze

Hi, List,

When I install some packages, to Squeeze, on a completely fresh VM, doesn’t
matter which ones, it fails around every 1-3’rd package with the same error1.

Steps to reproduce:

  1. xen-create-image --dist=squeeze
  2. ssh hostname; apt-get install htop lsof strace
  3. knife bootstrap hostname -x root -d ubuntu10.04-apt -P pwwwwwd
    While executing the “packages” recipe2, it fails with error1.

Some observations:

  • after 30 minutes, when client restarts, that package comes through nicely and
    stops with same error on other package.
  • it stucks on various packages I tried (vim, zsh, curl, nmap so far, 100%
    reproducible)
  • if I run chef-client manually, all works perfectly
  • everything exactly the same2 (cookbooks, VM installation, …) in lucid
    works perfectly

Need some ideas where to look. It would be best to get more verbose output from
apt-get, how do I do that?

I probably don’t have to mention that manually running
apt-get -q -y install vim=2:7.2.445+hg~cb94c42c0e1a-1

Works fine. So do other packages when installed manually.

I suspect TTY and apt… Can it be so that if apt does not have TTY, it behaves
differently on Squeeze? chef-client from command line makes me want to think
about it. How do I test apt-get without a TTY?

Any other ideas? If there is any more information I should provide, please tell
me.

Motiejus

P.S. I get different behaviour when installing apt-cacher-ng. It hangs here:

/usr/bin/ruby1.8 /usr/bin/chef-client -d -P /var/run/chef/client.pid -L /var/log/chef/client.log -c /etc/chef/client.rb -i 1800 -s 20
_ [chef-client]
_ apt-get -q -y install apt-cacher-ng=0.5.1-3
_ /bin/sh -c /usr/sbin/dpkg-preconfigure --apt || true
_ /usr/bin/perl -w /usr/sbin/dpkg-preconfigure --apt
_ [dpkg-preconfigu]
_ /bin/sh -e /tmp/apt-cacher-ng.config.60871 configure

Running chef-client manually works fine.

include cookbook 'apt' before you try to install packages.

error 100 is a generic failure, usually apt-get update needs to be run
-- a new source may have been added but not fetched, etc.

--AJ

2012/4/11 Motiejus Jakštys desired.mta@gmail.com:

Hi, List,

When I install some packages, to Squeeze, on a completely fresh VM, doesn't
matter which ones, it fails around every 1-3'rd package with the same error1.

Steps to reproduce:

  1. xen-create-image --dist=squeeze
  2. ssh hostname; apt-get install htop lsof strace
  3. knife bootstrap hostname -x root -d ubuntu10.04-apt -P pwwwwwd
    While executing the "packages" recipe2, it fails with error1.

Some observations:

  • after 30 minutes, when client restarts, that package comes through nicely and
    stops with same error on other package.
  • it stucks on various packages I tried (vim, zsh, curl, nmap so far, 100%
    reproducible)
  • if I run chef-client manually, all works perfectly
  • everything exactly the same2 (cookbooks, VM installation, ...) in lucid
    works perfectly

Need some ideas where to look. It would be best to get more verbose output from
apt-get, how do I do that?

I probably don't have to mention that manually running
apt-get -q -y install vim=2:7.2.445+hg~cb94c42c0e1a-1

Works fine. So do other packages when installed manually.

I suspect TTY and apt.. Can it be so that if apt does not have TTY, it behaves
differently on Squeeze? chef-client from command line makes me want to think
about it. How do I test apt-get without a TTY?

Any other ideas? If there is any more information I should provide, please tell
me.

Motiejus

P.S. I get different behaviour when installing apt-cacher-ng. It hangs here:

/usr/bin/ruby1.8 /usr/bin/chef-client -d -P /var/run/chef/client.pid -L /var/log/chef/client.log -c /etc/chef/client.rb -i 1800 -s 20
_ [chef-client]
_ apt-get -q -y install apt-cacher-ng=0.5.1-3
_ /bin/sh -c /usr/sbin/dpkg-preconfigure --apt || true
_ /usr/bin/perl -w /usr/sbin/dpkg-preconfigure --apt
_ [dpkg-preconfigu]
_ /bin/sh -e /tmp/apt-cacher-ng.config.60871 configure

Running chef-client manually works fine.

On Wed, Apr 11, 2012 at 08:53:57AM +1200, AJ Christensen wrote:

include cookbook 'apt' before you try to install packages.

Thanks, added.

error 100 is a generic failure, usually apt-get update needs to be run
-- a new source may have been added but not fetched, etc.

Still same. Here is the very first run, right after xen-create-image, running
"knife bootstrap". We see

[Wed, 11 Apr 2012 16:42:27 +0100] INFO: execute[apt-get-update] sh(apt-get update)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: execute[apt-get-update] ran successfully

However, normally, there is "apt-get update" output in between.

Any ideas?

Logfile created on Wed Apr 11 16:42:09 +0100 2012 by logger.rb/22285

[Wed, 11 Apr 2012 16:42:09 +0100] INFO: Daemonizing..
[Wed, 11 Apr 2012 16:42:09 +0100] INFO: Forked, in 5769. Priveleges: 0 0
[Wed, 11 Apr 2012 16:42:24 +0100] INFO: *** Chef 0.10.8 ***
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Client key /etc/chef/client.pem is not present - registering
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Run List is [role[debian], role[apt]]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Run List expands to [apt, packages, ntp, chef-client, users::sysadmins, sudo]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Starting Chef Run for t12.src.gla.ac.uk
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Running start handlers
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Start handlers complete.
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Loading cookbooks [apt, chef-client, ntp, packages, sudo, users]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Storing updated cookbooks/sudo/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Storing updated cookbooks/sudo/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/resources/repository.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/providers/repository.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/cacher-client.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/cacher-ng.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/CONTRIBUTING in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/LICENSE in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/CHANGELOG.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/delete_validation.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/config.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/service.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/recipes/sysadmins.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/README.md in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/README.md in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: execute[apt-get-update] sh(apt-get update)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: execute[apt-get-update] ran successfully
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: Processing package[update-notifier-common] action install (apt::default line 36)
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: package[update-notifier-common] (apt::default line 36) has had an error
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: package[update-notifier-common] (/var/cache/chef/cookbooks/apt/recipes/default.rb:36:in from_file') had an error: package[update-notifier-common] (apt::default line 36) had an error: Chef::Exceptions::Exec: apt-get -q -y install update-notifier-common=0.99.3debian8 returned 100, expected 0 /usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:127:in handle_command_failures'
/usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:74:in run_command' /usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:142:in run_command_with_systems_locale'
/usr/lib/ruby/vendor_ruby/chef/provider/package/apt.rb:92:in install_package' /usr/lib/ruby/vendor_ruby/chef/provider/package.rb:60:in action_install'
/usr/lib/ruby/vendor_ruby/chef/resource.rb:440:in send' /usr/lib/ruby/vendor_ruby/chef/resource.rb:440:in run_action'
/usr/lib/ruby/vendor_ruby/chef/runner.rb:45:in run_action' /usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in converge'
/usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in each' /usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in converge'
/usr/lib/ruby/vendor_ruby/chef/resource_collection.rb:94:in execute_each_resource' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:116:in call'
/usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:116:in call_iterator_block' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:85:in step'
/usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:104:in iterate' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:55:in each_with_index'
/usr/lib/ruby/vendor_ruby/chef/resource_collection.rb:92:in execute_each_resource' /usr/lib/ruby/vendor_ruby/chef/runner.rb:76:in converge'
/usr/lib/ruby/vendor_ruby/chef/client.rb:312:in converge' /usr/lib/ruby/vendor_ruby/chef/client.rb:160:in run'
/usr/lib/ruby/vendor_ruby/chef/application/client.rb:239:in run_application' /usr/lib/ruby/vendor_ruby/chef/application/client.rb:229:in loop'
/usr/lib/ruby/vendor_ruby/chef/application/client.rb:229:in run_application' /usr/lib/ruby/vendor_ruby/chef/application.rb:67:in run'
/usr/bin/chef-client:25
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Running exception handlers
[Wed, 11 Apr 2012 16:42:32 +0100] FATAL: Saving node information to /var/cache/chef/failed-run-data.json
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Exception handlers complete
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Chef::Exceptions::Exec: package[update-notifier-common] (apt::default line 36) had an error: Chef::Exceptions::Exec: apt-get -q -y install update-notifier-common=0.99.3debian8 returned 100, expected 0
[Wed, 11 Apr 2012 16:42:32 +0100] FATAL: Stacktrace dumped to /var/cache/chef/chef-stacktrace.out
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Sleeping for 1800 seconds before trying again

Motiejus

If you run "apt-get -q -y install
update-notifier-common=0.99.3debian8" manually what happens?

2012/4/11 Motiejus Jakštys desired.mta@gmail.com:

On Wed, Apr 11, 2012 at 08:53:57AM +1200, AJ Christensen wrote:

include cookbook 'apt' before you try to install packages.

Thanks, added.

error 100 is a generic failure, usually apt-get update needs to be run
-- a new source may have been added but not fetched, etc.

Still same. Here is the very first run, right after xen-create-image, running
"knife bootstrap". We see

[Wed, 11 Apr 2012 16:42:27 +0100] INFO: execute[apt-get-update] sh(apt-get update)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: execute[apt-get-update] ran successfully

However, normally, there is "apt-get update" output in between.

Any ideas?

Logfile created on Wed Apr 11 16:42:09 +0100 2012 by logger.rb/22285

[Wed, 11 Apr 2012 16:42:09 +0100] INFO: Daemonizing..
[Wed, 11 Apr 2012 16:42:09 +0100] INFO: Forked, in 5769. Priveleges: 0 0
[Wed, 11 Apr 2012 16:42:24 +0100] INFO: *** Chef 0.10.8 ***
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Client key /etc/chef/client.pem is not present - registering
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Run List is [role[debian], role[apt]]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Run List expands to [apt, packages, ntp, chef-client, users::sysadmins, sudo]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Starting Chef Run for t12.src.gla.ac.uk
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Running start handlers
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Start handlers complete.
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Loading cookbooks [apt, chef-client, ntp, packages, sudo, users]
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Storing updated cookbooks/sudo/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:25 +0100] INFO: Storing updated cookbooks/sudo/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/sudo/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/packages/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/resources/repository.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/providers/repository.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/cacher-client.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/recipes/cacher-ng.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/CONTRIBUTING in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/LICENSE in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/CHANGELOG.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/apt/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/delete_validation.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/config.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/recipes/service.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/README.md in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:26 +0100] INFO: Storing updated cookbooks/chef-client/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/recipes/sysadmins.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/README.md in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/users/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/recipes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/attributes/default.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/README.md in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/metadata.rb in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Storing updated cookbooks/ntp/metadata.json in the cache.
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
[Wed, 11 Apr 2012 16:42:27 +0100] INFO: execute[apt-get-update] sh(apt-get update)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: execute[apt-get-update] ran successfully
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)
[Wed, 11 Apr 2012 16:42:28 +0100] INFO: Processing package[update-notifier-common] action install (apt::default line 36)
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: package[update-notifier-common] (apt::default line 36) has had an error
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: package[update-notifier-common] (/var/cache/chef/cookbooks/apt/recipes/default.rb:36:in from_file') had an error: package[update-notifier-common] (apt::default line 36) had an error: Chef::Exceptions::Exec: apt-get -q -y install update-notifier-common=0.99.3debian8 returned 100, expected 0 /usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:127:in handle_command_failures'
/usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:74:in run_command' /usr/lib/ruby/vendor_ruby/chef/mixin/command.rb:142:in run_command_with_systems_locale'
/usr/lib/ruby/vendor_ruby/chef/provider/package/apt.rb:92:in install_package' /usr/lib/ruby/vendor_ruby/chef/provider/package.rb:60:in action_install'
/usr/lib/ruby/vendor_ruby/chef/resource.rb:440:in send' /usr/lib/ruby/vendor_ruby/chef/resource.rb:440:in run_action'
/usr/lib/ruby/vendor_ruby/chef/runner.rb:45:in run_action' /usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in converge'
/usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in each' /usr/lib/ruby/vendor_ruby/chef/runner.rb:81:in converge'
/usr/lib/ruby/vendor_ruby/chef/resource_collection.rb:94:in execute_each_resource' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:116:in call'
/usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:116:in call_iterator_block' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:85:in step'
/usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:104:in iterate' /usr/lib/ruby/vendor_ruby/chef/resource_collection/stepable_iterator.rb:55:in each_with_index'
/usr/lib/ruby/vendor_ruby/chef/resource_collection.rb:92:in execute_each_resource' /usr/lib/ruby/vendor_ruby/chef/runner.rb:76:in converge'
/usr/lib/ruby/vendor_ruby/chef/client.rb:312:in converge' /usr/lib/ruby/vendor_ruby/chef/client.rb:160:in run'
/usr/lib/ruby/vendor_ruby/chef/application/client.rb:239:in run_application' /usr/lib/ruby/vendor_ruby/chef/application/client.rb:229:in loop'
/usr/lib/ruby/vendor_ruby/chef/application/client.rb:229:in run_application' /usr/lib/ruby/vendor_ruby/chef/application.rb:67:in run'
/usr/bin/chef-client:25
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Running exception handlers
[Wed, 11 Apr 2012 16:42:32 +0100] FATAL: Saving node information to /var/cache/chef/failed-run-data.json
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Exception handlers complete
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Chef::Exceptions::Exec: package[update-notifier-common] (apt::default line 36) had an error: Chef::Exceptions::Exec: apt-get -q -y install update-notifier-common=0.99.3debian8 returned 100, expected 0
[Wed, 11 Apr 2012 16:42:32 +0100] FATAL: Stacktrace dumped to /var/cache/chef/chef-stacktrace.out
[Wed, 11 Apr 2012 16:42:32 +0100] ERROR: Sleeping for 1800 seconds before trying again

Motiejus

On Wed, Apr 11, 2012 at 10:57:13AM -0500, Matt Ray wrote:

If you run "apt-get -q -y install
update-notifier-common=0.99.3debian8" manually what happens?

It works perfectly fine both ran before and after knife bootstrap. I think I
mentioned this in previous email.

Motiejus

2012/4/10 Motiejus Jakštys desired.mta@gmail.com:

Need some ideas where to look. It would be best to get more verbose output from
apt-get, how do I do that?

Since you're using the apt bootstrap, /etc/chef/client.rb is created
by the chef debian package. You could edit this bootstrap template and
add this right after the the 'apt-get install -y chef' line:

sed -ie 's/ :info/ :debug/' /etc/chef/client.rb

That should change the log level for the chef client to debug, and
when knife bootstrap runs chef_client, it should read this value and
produce extra output from the apt-get run during the chef-client run.

Bryan

On Wed, Apr 11, 2012 at 01:04:39PM -0400, Bryan McLellan wrote:

2012/4/10 Motiejus Jakštys desired.mta@gmail.com:

Need some ideas where to look. It would be best to get more verbose output from
apt-get, how do I do that?

Since you're using the apt bootstrap, /etc/chef/client.rb is created
by the chef debian package. You could edit this bootstrap template and
add this right after the the 'apt-get install -y chef' line:

sed -ie 's/ :info/ :debug/' /etc/chef/client.rb

That should change the log level for the chef client to debug, and
when knife bootstrap runs chef_client, it should read this value and
produce extra output from the apt-get run during the chef-client run.

Good advise, helped me to troubleshoot some other problems already.
:slight_smile: Thanks.

This does the same, but does not depend on spaces and has no quotes:
sed -i /^log_level/s/info/debug/ /etc/chef/client.rb

However, after putting this line to the template after apt-get install -y chef,
I still get only "info" debug level information in the output with exactly the
same result as before. I checked log_level in /etc/chef/client.rb at some point
in time, it is :debug (so the command was executed successfully).

If you say it should work, have you tried it? If change of debug level at
bootstrapping time does work for you, then it is quite interesting. On what
system exactly and what chef version?

Waiting for 30 minutes to see the output of another run, should be proper
:debug.

Motiejus

On Wed, Apr 11, 2012 at 11:31:50PM +0300, Motiejus Jakštys wrote:

On Wed, Apr 11, 2012 at 01:04:39PM -0400, Bryan McLellan wrote:

2012/4/10 Motiejus Jakštys desired.mta@gmail.com:

Need some ideas where to look. It would be best to get more verbose output from
apt-get, how do I do that?

Since you're using the apt bootstrap, /etc/chef/client.rb is created
by the chef debian package. You could edit this bootstrap template and
add this right after the the 'apt-get install -y chef' line:

sed -ie 's/ :info/ :debug/' /etc/chef/client.rb

That should change the log level for the chef client to debug, and
when knife bootstrap runs chef_client, it should read this value and
produce extra output from the apt-get run during the chef-client run.

Good advise, helped me to troubleshoot some other problems already.
:slight_smile: Thanks.

This does the same, but does not depend on spaces and has no quotes:
sed -i /^log_level/s/info/debug/ /etc/chef/client.rb

After 30 minutes it does not change log level, because it does not re-read the
configuration file. And same failure.. without logging information.

If template looks like this:
apt-get install -y chef
sed -i /^log_level/s/info/debug/ /etc/chef/client.rb
/etc/init.d/chef-client restart
(last two lines added by me), I can see the debug log, and.. It works fine.

If I just restart chef-client, it also works fine (without changing the
debug level).

Should I report a bug?

Relevance: if I do not restart chef-client in the template, it does not install
necessary packages on the initial bootstrap (and I see no way to get the debug
info, unless I build my own chef-client package with log_level :debug). If I
restart chef-client by hand or restart the node, it goes fine.

Though set up properly (everything works), can an enforced http proxy trigger
apt-get update error? It's set up properly (in apt preferences), but still,
first run..

Motiejus