Users cookbook: Internal Server Error: Connection refused

Hi all,

I’m experiencing a strange problem when trying to add users using the users cookbook. I’m getting “HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)” error. If I remove the users cookbook then chef-client will complete without any errors.

[Wed, 11 Apr 2012 07:17:34 +0000] INFO: Processing package[sudo] action upgrade (sudo::default line 20)
[Wed, 11 Apr 2012 07:17:40 +0000] INFO: Processing template[/etc/sudoers] action create (sudo::default line 24)
[Wed, 11 Apr 2012 07:17:40 +0000] INFO: Processing execute[disable selinux enforcement] action run (selinux::disabled line 21)
[Wed, 11 Apr 2012 07:17:40 +0000] INFO: Processing template[/etc/selinux/config] action create (selinux::disabled line 27)
[Wed, 11 Apr 2012 07:17:40 +0000] INFO: Processing remote_file[/var/chef/cache/epel-release-6-5.noarch.rpm] action create (yum::epel line 26)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing rpm_package[epel-release] action install (yum::epel line 32)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing template[/etc/yum.conf] action create (yum::yum line 21)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing bash[addrepo] action run (postgresql9::server_91_redhat line 10)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing package[postgresql91-server] action install (postgresql9::server_91_redhat line 20)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing template[pg_hba.conf] action create (postgresql9::server_91_redhat line 24)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing service[postgresql-9.1] action enable (postgresql9::server_91_redhat line 38)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing service[postgresql-9.1] action start (postgresql9::server_91_redhat line 38)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing ruby_block[set-env-java-home] action create (java::openjdk line 36)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: ruby_block[set-env-java-home] called
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing ruby_block[update-java-alternatives] action nothing (java::openjdk line 43)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing package[java-1.6.0-openjdk] action install (java::openjdk line 79)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing package[java-1.6.0-openjdk-devel] action install (java::openjdk line 79)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing users_manage[sysadmin] action remove (users::sysadmins line 23)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:17:41 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 1/5 in 4s
[Wed, 11 Apr 2012 07:17:46 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:17:46 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 2/5 in 7s
[Wed, 11 Apr 2012 07:17:53 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:17:53 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 3/5 in 13s
[Wed, 11 Apr 2012 07:18:07 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:18:07 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 4/5 in 28s
[Wed, 11 Apr 2012 07:18:35 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:18:35 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 5/5 in 49s
[Wed, 11 Apr 2012 07:19:24 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:19:24 +0000] ERROR: users_manage[sysadmin] (users::sysadmins line 23) has had an error
[Wed, 11 Apr 2012 07:19:24 +0000] ERROR: users_manage[sysadmin] (/var/chef/cache/cookbooks/users/recipes/sysadmins.rb:23:in from_file') had an error: users_manage[sysadmin] (users::sysadmins line 23) had an error: Net::HTTPFatalError: 500 "Internal Server Error" /usr/lib/ruby/1.8/net/http.rb:2105:inerror!’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/rest.rb:245:in api_request' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/rest.rb:296:inretriable_rest_request’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/rest.rb:226:in api_request' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/rest.rb:114:inget_rest’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/search/query.rb:42:in search' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/mixin/language.rb:133:insearch’
/var/chef/cache/cookbooks/users/providers/manage.rb:27:in class_from_file' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/provider.rb:104:ininstance_eval’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/provider.rb:104:in action_remove' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/resource.rb:440:insend’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/resource.rb:440:in run_action' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/runner.rb:45:inrun_action’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/runner.rb:81:in converge' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/runner.rb:81:ineach’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/runner.rb:81:in converge' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/resource_collection.rb:94:inexecute_each_resource’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/resource_collection/stepable_iterator.rb:116:in call' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/resource_collection/stepable_iterator.rb:116:incall_iterator_block’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/resource_collection/stepable_iterator.rb:85:in step' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/resource_collection/stepable_iterator.rb:104:initerate’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/resource_collection/stepable_iterator.rb:55:in each_with_index' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/resource_collection.rb:92:inexecute_each_resource’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/runner.rb:76:in converge' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/client.rb:312:inconverge’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/client.rb:160:in run' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/application/client.rb:239:inrun_application’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/application/client.rb:229:in loop' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/../lib/chef/application/client.rb:229:inrun_application’
/usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/…/lib/chef/application.rb:67:in run' /usr/lib/ruby/gems/1.8/gems/chef-0.10.6/bin/chef-client:26 /usr/bin/chef-client:19:inload’
/usr/bin/chef-client:19
[Wed, 11 Apr 2012 07:19:24 +0000] ERROR: Running exception handlers
[Wed, 11 Apr 2012 07:19:24 +0000] FATAL: Saving node information to /var/chef/cache/failed-run-data.json
[Wed, 11 Apr 2012 07:19:24 +0000] ERROR: Exception handlers complete
[Wed, 11 Apr 2012 07:19:24 +0000] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[Wed, 11 Apr 2012 07:19:24 +0000] FATAL: Net::HTTPFatalError: users_manage[sysadmin] (users::sysadmins line 23) had an error: Net::HTTPFatalError: 500 “Internal Server Error”

Port 4000 on the chef server is accessible from everywhere. The fact that a chef run will complete when I remove the users cookbook confirms this.

~]# telnet 41.66.152.201 4000
Trying 41.66.152.201…
Connected to 41.66.152.201.
Escape character is ‘^]’.

Connection closed by foreign host.

Has anyone had a similar issue before?

Regards,
Marc

On Wed, Apr 11, 2012 at 5:27 PM, Marc Peiser marc@itmatter.co.za wrote:

[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing users_manage[sysadmin] action remove (users::sysadmins line 23)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:17:41 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 1/5 in 4s
[Wed, 11 Apr 2012 07:17:46 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
...
Has anyone had a similar issue before?

The problem has occurred when the chef server attempted to access the
solr server. Check solr is running correctly.

If you are running this on ubuntu it is possible that solr is not
starting because the log directory permissions are incorrect -
probably due to activity of logrotated. This seems to be a common
problem with the recent releases.

--
Cheers,

Peter Donald

Thank you Peter.

Turns out it was the /var/run/chef directory that didn't have the correct permissions.. although chef-solr was running. Fixed permissions and restarted chef-solr and it's works.

Regards
Marc

On 11 Apr 2012, at 9:31 AM, Peter Donald wrote:

On Wed, Apr 11, 2012 at 5:27 PM, Marc Peiser marc@itmatter.co.za wrote:

[Wed, 11 Apr 2012 07:17:41 +0000] INFO: Processing users_manage[sysadmin] action remove (users::sysadmins line 23)
[Wed, 11 Apr 2012 07:17:41 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
[Wed, 11 Apr 2012 07:17:41 +0000] ERROR: Server returned error for http://41.66.152.201:4000/search/users?q=groups:sysadmin%20AND%20action:remove&sort=X_CHEF_id_CHEF_X%20asc&start=0&rows=1000, retrying 1/5 in 4s
[Wed, 11 Apr 2012 07:17:46 +0000] INFO: HTTP Request Returned 500 Internal Server Error: Connection refused - connect(2)
...
Has anyone had a similar issue before?

The problem has occurred when the chef server attempted to access the
solr server. Check solr is running correctly.

If you are running this on ubuntu it is possible that solr is not
starting because the log directory permissions are incorrect -
probably due to activity of logrotated. This seems to be a common
problem with the recent releases.

--
Cheers,

Peter Donald