Error uploading Cookbooks

Mark_Pimentel · March 6, 2013, 9:12pm

I am trying to upload a cookbook to my Chef 11.0.2 server and I am getting
an error.

DEBUG: ---- HTTP Status and Header Data: ----
DEBUG: HTTP 1.1 500 Internal Server Error
DEBUG: server: nginx/1.2.3
DEBUG: date: Wed, 06 Mar 2013 20:27:39 GMT
DEBUG: content-type: application/json
DEBUG: content-length: 36
DEBUG: connection: close
DEBUG: x-ops-api-info: flavor=osc;version=11.0.2;erchef=1.2.5
DEBUG: ---- End HTTP Status/Header Data ----
INFO: HTTP Request Returned 500 Internal Server Error: internal service
error
ERROR: Server returned error for
https://hq-tor-chef.quickplay.local/sandboxes/0000000000001c52a724fedde7f52add,
retrying 1/5 in 3s

This only occurs on cookbooks, not roles, data_bags etc.

–
Thanks,

Mark

kallistec · March 6, 2013, 9:21pm

On Wednesday, March 6, 2013 at 1:12 PM, Mark Pimentel wrote:

I am trying to upload a cookbook to my Chef 11.0.2 server and I am getting an error.

DEBUG: ---- HTTP Status and Header Data: ----
DEBUG: HTTP 1.1 500 Internal Server Error
DEBUG: server: nginx/1.2.3
DEBUG: date: Wed, 06 Mar 2013 20:27:39 GMT
DEBUG: content-type: application/json
DEBUG: content-length: 36
DEBUG: connection: close
DEBUG: x-ops-api-info: flavor=osc;version=11.0.2;erchef=1.2.5
DEBUG: ---- End HTTP Status/Header Data ----
INFO: HTTP Request Returned 500 Internal Server Error: internal service error
ERROR: Server returned error for https://hq-tor-chef.quickplay.local/sandboxes/0000000000001c52a724fedde7f52add, retrying 1/5 in 3s

This only occurs on cookbooks, not roles, data_bags etc.

--
Thanks,

Mark
Can you get relevant logs with chef-server-ctl tail and share them?

--
Daniel DeLeo

Baruch_Shpirer · March 6, 2013, 9:44pm

Attaching some logs while trying to do cookbook upload

==> /var/log/chef-server/erchef/current <==
2013-03-06_21:13:49.98214 {webmachine_resource,do,3,
2013-03-06_21:13:49.98214 [{file,“src/webmachine_resource.erl”},{line,125}]},
2013-03-06_21:13:49.98215 {webmachine_decision_core,resource_call,1,
2013-03-06_21:13:49.98215 [{file,“src/webmachine_decision_core.erl”},{line,48}]},
2013-03-06_21:13:49.98215 {webmachine_decision_core,accept_helper,0,
2013-03-06_21:13:49.98216 [{file,“src/webmachine_decision_core.erl”},{line,583}]},
2013-03-06_21:13:49.98216 {webmachine_decision_core,decision,1,
2013-03-06_21:13:49.98216 [{file,“src/webmachine_decision_core.erl”},{line,489}]},
2013-03-06_21:13:49.98217 {webmachine_decision_core,handle_request,2,
2013-03-06_21:13:49.98218 [{file,“src/webmachine_decision_core.erl”},{line,33}]}]}}

==> /var/log/chef-server/nginx/access.log <==
192.168.75.74 - - [06/Mar/2013:16:40:58 -0500] “GET /cookbooks?num_versions=all HTTP/1.1” 200 “0.020” 979 “-” “Chef Knife/0.10.10 (ruby-1.9.2-p180; ohai-0.6.12; x86_64-linux; +http://opscode.com)” “127.0.0.1:8000” “200” “0.013” “0.10.10” “version=1.0” “baruchs” “2013-03-06T21:40:58Z” “2jmj7l5rSw0yVb/vlWAYkK/YBwk=” 940
192.168.75.74 - - [06/Mar/2013:16:40:58 -0500] “POST /sandboxes HTTP/1.1” 201 “0.070” 752 “-” “Chef Knife/0.10.10 (ruby-1.9.2-p180; ohai-0.6.12; x86_64-linux; +http://opscode.com)” “127.0.0.1:8000” “201” “0.023” “0.10.10” “version=1.0” “baruchs” “2013-03-06T21:40:58Z” “17WVwc7QAnAtCnOlTAlgc5YUZM8=” 1232
192.168.75.74 - - [06/Mar/2013:16:40:58 -0500] “PUT /bookshelf/organization-00000000000000000000000000000000/checksum-960131de20bb72d55d52df914d73a5e2?AWSAccessKeyId=e849c1918a22eabefc7e7832b27173ab5b93016d&Expires=1362606958&Signature=G5O2Ex3Gz7l0aWmmwyiHRPQFmI0%3D HTTP/1.1” 204 “0.014” 0 “-” “Ruby” “127.0.0.1:4321” “204” “0.007” “-” “version=1.0” “baruchs” “2013-03-06T21:40:58Z” “hZyLgj7RPtRg/pSvY7LOq2Fotrc=” 3573

==> /var/log/chef-server/erchef/erchef.log.1 <==
2013-03-06T21:40:58Z erchef@127.0.0.1 INFO req_id=rXyk1ks5Taz5qtOTGtPtuQ==; status=200; method=GET; path=/cookbooks?num_versions=all; user=baruchs; msg=[]; req_time=9; rdbms_time=3; rdbms_count=2
2013-03-06T21:40:58Z erchef@127.0.0.1 INFO req_id=2Qzog7D0fQQx3g3z1KUPZQ==; status=201; method=POST; path=/sandboxes; user=baruchs; msg=[]; req_time=20; rdbms_time=16; rdbms_count=3

==> /var/log/chef-server/erchef/current <==
2013-03-06_21:41:03.84624
2013-03-06_21:41:03.84638 =ERROR REPORT==== 6-Mar-2013::16:41:03 ===
2013-03-06_21:41:03.84639 Checking presence of checksum: <<“960131de20bb72d55d52df914d73a5e2”>> for org <<“00000000000000000000000000000000”>> from bucket “bookshelf” has taken longer than 5000 ms

==> /var/log/chef-server/nginx/access.log <==
192.168.75.74 - - [06/Mar/2013:16:41:03 -0500] “PUT /sandboxes/000000000000be13430442db7a83ab5f HTTP/1.1” 500 “5.059” 36 “-” “Chef Knife/0.10.10 (ruby-1.9.2-p180; ohai-0.6.12; x86_64-linux; +http://opscode.com)” “127.0.0.1:8000” “500” “5.010” “0.10.10” “version=1.0” “baruchs” “2013-03-06T21:40:58Z” “oMRtV6loUDnbKJuGcW6nqBbF8ww=” 1029

==> /var/log/chef-serv 2013-03-06_21:41:03.84851
2013-03-06_21:41:03.84854 2013-03-06_21:41:03.84854 2013-03-06_21:41:03.84855 {error,
2013-03-06_21:41:03.84860 2013-03-06_21:41:03.84861 2013-03-06_21:41:03.84862 2013-03-06_21:41:03.84862 2013-03-06_21:41:03.84864 2013-03-06_21:41:03.84865 2013-03-06_21:41:03.84865 2013-03-06_21:41:03.84866 2013-03-06_21:41:03.84867 2013-03-06_21:41:03.84867 2013-03-06_21:41:03.84868 2013-03-06_21:41:03.84869 2013-03-06_21:41:03.84869 2013-03-06_21:41:03.84870 2013-03-06_21:41:03.84871 2013-03-06_21:41:03.84871 2013-03-06_21:41:03.84872 2013-03-06_21:41:03.84874 er/erchef/current <==
=ERROR REPORT==== 6-Mar-2013::16:41:03 ===
webmachine error: path="/sandboxes/000000000000be13430442db7a83ab5f"
{throw,
{checksum_check_error,1},
[{chef_wm_named_sandbox,validate_checksums_uploaded,2,
[{file,“src/chef_wm_named_sandbox.erl”},{line,144}]},
{chef_wm_named_sandbox,from_json,2,
[{file,“src/chef_wm_named_sandbox.erl”},{line,99}]},
{webmachine_resource,resource_call,3,
[{file,“src/webmachine_resource.erl”},{line,166}]},
{webmachine_resource,do,3,
[{file,“src/webmachine_resource.erl”},{line,125}]},
{webmachine_decision_core,resource_call,1,
[{file,“src/webmachine_decision_core.erl”},{line,48}]},
{webmachine_decision_core,accept_helper,0,
[{file,“src/webmachine_decision_core.erl”},{line,583}]},
{webmachine_decision_core,decision,1,
[{file,“src/webmachine_decision_core.erl”},{line,489}]},
{webmachine_decision_core,handle_request,2,
[{file,“src/webmachine_decision_core.erl”},{line,33}]}]}}

==> /var/log/chef-server/erchef/erchef.log.1 <==
2013-03-06T21:41:03Z erchef@127.0.0.1 ERR req_id=FOOYERUCt/btbq9O/5AAkg==; status=500; method=PUT; path=/sandboxes/000000000000be13430442db7a83ab5f; user=baruchs; msg=[]; req_time=5007; rdbms_time=3; rdbms_count=2; s3_time=5000; s3_count=1

From: Daniel DeLeo [mailto:ddeleo@kallistec.com] On Behalf Of Daniel DeLeo
Sent: Wednesday, March 06/03/2013 16:21
To: chef@lists.opscode.com
Subject: [chef] Re: Error uploading Cookbooks

On Wednesday, March 6, 2013 at 1:12 PM, Mark Pimentel wrote:
I am trying to upload a cookbook to my Chef 11.0.2 server and I am getting an error.

DEBUG: ---- HTTP Status and Header Data: ----
DEBUG: HTTP 1.1 500 Internal Server Error
DEBUG: server: nginx/1.2.3
DEBUG: date: Wed, 06 Mar 2013 20:27:39 GMT
DEBUG: content-type: application/json
DEBUG: content-length: 36
DEBUG: connection: close
DEBUG: x-ops-api-info: flavor=osc;version=11.0.2;erchef=1.2.5
DEBUG: ---- End HTTP Status/Header Data ----
INFO: HTTP Request Returned 500 Internal Server Error: internal service error
ERROR: Server returned error for https://hq-tor-chef.quickplay.local/sandboxes/0000000000001c52a724fedde7f52add, retrying 1/5 in 3s

This only occurs on cookbooks, not roles, data_bags etc.

–
Thanks,

Mark
Can you get relevant logs with chef-server-ctl tail and share them?

–
Daniel DeLeo

Seth_Falcon_01 · March 6, 2013, 11:51pm

Hi there,

In the logs I see this bit, which seems to be getting closer to the cause of the issues you are seeing:

2013-03-06_21:41:03.84638 =ERROR REPORT==== 6-Mar-2013::16:41:03 ===
2013-03-06_21:41:03.84639 Checking presence of checksum: <<"960131de20bb72d55d52df914d73a5e2">> for org <<"00000000000000000000000000000000">> from bucket "bookshelf" has taken longer than 5000 ms

It would be interesting to see if you always see this error leading up to the cookbook upload failure and if it is for the same checksum or different checksums.

The timeout is tunable, but unless your server is under considerable load, I would have expected that you'd run into this -- so there may be something else going on or a bug we will identify

As an aside, it would be worth upgrading to 11.0.6 as there are some security fixes that are worth having.

On Mar 6, 2013, at 1:44 PM, Baruch Shpirer wrote:

192.168.75.74 - - [06/Mar/2013:16:40:58 -0500] "POST /sandboxes HTTP/1.1" 201 "0.070" 752 "-" "Chef Knife/0.10.10 (ruby-1.9.2-p180; ohai-0.6.12; x86_64-linux; +http://opscode.com)" "127.0.0.1:8000" "201" "0.023" "0.10.10" "version=1.0" "baruchs" "2013-03-06T21:40:58Z" "17WVwc7QAnAtCnOlTAlgc5YUZM8=" 1232

So a sandbox was created.

192.168.75.74 - - [06/Mar/2013:16:40:58 -0500] "PUT /bookshelf/organization-00000000000000000000000000000000/checksum-960131de20bb72d55d52df914d73a5e2?AWSAccessKeyId=e849c1918a22eabefc7e7832b27173ab5b93016d&Expires=1362606958&Signature=G5O2Ex3Gz7l0aWmmwyiHRPQFmI0%3D HTTP/1.1" 204 "0.014" 0 "-" "Ruby" "127.0.0.1:4321" "204" "0.007" "-" "version=1.0" "baruchs" "2013-03-06T21:40:58Z" "hZyLgj7RPtRg/pSvY7LOq2Fotrc=" 3573

The problem checksum appears to have been successfully uploaded to bookshelf. You could verify that it is on disk by looking in /var/opt/chef-server/bookshelf/data for a file with the 960131de20bb72d55d52df914d73a5e2 in its name.

==> /var/log/chef-server/erchef/erchef.log.1 <==
2013-03-06T21:40:58Z erchef@127.0.0.1 INFO req_id=rXyk1ks5Taz5qtOTGtPtuQ==; status=200; method=GET; path=/cookbooks?num_versions=all; user=baruchs; msg=; req_time=9; rdbms_time=3; rdbms_count=2
2013-03-06T21:40:58Z erchef@127.0.0.1 INFO req_id=2Qzog7D0fQQx3g3z1KUPZQ==; status=201; method=POST; path=/sandboxes; user=baruchs; msg=; req_time=20; rdbms_time=16; rdbms_count=3

==> /var/log/chef-server/erchef/current <==
2013-03-06_21:41:03.84624
2013-03-06_21:41:03.84638 =ERROR REPORT==== 6-Mar-2013::16:41:03 ===
2013-03-06_21:41:03.84639 Checking presence of checksum: <<"960131de20bb72d55d52df914d73a5e2">> for org <<"00000000000000000000000000000000">> from bucket "bookshelf" has taken longer than 5000 ms

==> /var/log/chef-server/nginx/access.log <==
192.168.75.74 - - [06/Mar/2013:16:41:03 -0500] "PUT /sandboxes/000000000000be13430442db7a83ab5f HTTP/1.1" 500 "5.059" 36 "-" "Chef Knife/0.10.10 (ruby-1.9.2-p180; ohai-0.6.12; x86_64-linux; +http://opscode.com)" "127.0.0.1:8000" "500" "5.010" "0.10.10" "version=1.0" "baruchs" "2013-03-06T21:40:58Z" "oMRtV6loUDnbKJuGcW6nqBbF8ww=" 1029

Here we see the error report for the failure to verify the existance of the checksum in bookshelf and then the 500 for the request trying to commit the sandbox.

Does this happen for any cookbook upload? E.g. can you see what happens if you try to upload one of the community cookbooks?

seth

Baruch_Shpirer · March 7, 2013, 4:15am

We found the problem, we changed IP and the older one was still in /etc/hosts and nginx didn’t like it
Thanks for the help

-----Original Message-----
From: Seth Falcon [mailto:seth@opscode.com]
Sent: Wednesday, March 06/03/2013 18:51
To: chef@lists.opscode.com
Subject: [chef] Re: Error uploading Cookbooks