Re: Error 500 when testing new v229 CF deployment


Dieu Cao <dcao@...>
 

Hi James,

That sounds like you might be using a self signed cert and CC is failing
trying to do cert verification.
You can try specifying in your manifest properties.ssl.skip_cert_verify:
true
https://github.com/cloudfoundry/cf-release/blob/master/jobs/cloud_controller_ng/spec#L44
We have a bug created recently to try to return a more helpful error
instead of a 500 for this case.
https://www.pivotaltracker.com/story/show/112371013

Hope that helps.

-Dieu
CF CAPI PM

On Wed, Jan 27, 2016 at 3:59 AM, James Leavers <james(a)cloudhelix.io> wrote:

Hi,

I have just set up a fresh v229 install to do some testing with - the bosh
deployment appeared to complete successfully and all the VMs are running,
however anything after initial authentication fails with an error 500:

iMac:~ jim$ cf login
API endpoint: https://api.app.x.y

Email> admin

Password>
Authenticating...
OK

FAILED
Error finding available orgs
Server error, status code: 500, error code: 10001, message: An unknown
error occurred.


API endpoint: https://api.app.x.y (API version: 2.47.0)
User: admin
No org or space targeted, use 'cf target -o ORG -s SPACE'

iMac:~ jim$ CF_TRACE=true cf orgs
Getting orgs as admin...


REQUEST: [2016-01-27T11:48:25Z]
GET /v2/organizations HTTP/1.1
Host: api.app.x.y
Accept: application/json
Authorization: [PRIVATE DATA HIDDEN]
Content-Type: application/json
User-Agent: go-cli 6.15.0+fa1bfe2 / darwin



RESPONSE: [2016-01-27T11:48:26Z]
HTTP/1.1 500 Internal Server Error
Content-Length: 99
Content-Type: application/json;charset=utf-8
Date: Wed, 27 Jan 2016 11:48:26 GMT
Server: nginx
X-Cf-Requestid: fbf3ba39-65fd-4e21-67a5-f3ba7f9c0330
X-Content-Type-Options: nosniff
X-Vcap-Request-Id:
471ad2c7-0e09-46a9-6a31-6fe5024a1084::f9173c33-ee11-4513-a124-6ab04a37484d

{
"error_code": "UnknownError",
"description": "An unknown error occurred.",
"code": 10001
}

FAILED
Server error, status code: 500, error code: 10001, message: An unknown
error occurred.
FAILED
Server error, status code: 500, error code: 10001, message: An unknown
error occurred.

I had a look in cloud_controller_ng.log on api_z1/0 & api_z2/0 and can see
the requests failing as follows:

{"timestamp":1453833820.1395981,"message":"Started GET
\"/v2/organizations\" for 86.152.144.203 with vcap-request-id:
d44f2a12-873f-437f-7d2c-f261f503640f::1d2ea0bc-1a78-49ea-85ff-bfb9c11d2f2b
at 2016-01-26 18:43:40
UTC","log_level":"info","source":"cc.api","data":{},"thread_id":47241509083720,"fiber_id":47241507190360,"process_id":5222,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/request_logs.rb","lineno":12,"method":"call"}
{"timestamp":1453833820.1408544,"message":"Request failed: 500:
{\"code\"=>10001, \"description\"=>\"Neither PUB key nor PRIV key: header
too long\", \"error_code\"=>\"CF-RSAError\",
\"backtrace\"=>[\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/cache/cf-uaa-lib-b1e11235dc6c/lib/uaa/token_coder.rb:51:in
`initialize'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/cache/cf-uaa-lib-b1e11235dc6c/lib/uaa/token_coder.rb:51:in
`new'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/cache/cf-uaa-lib-b1e11235dc6c/lib/uaa/token_coder.rb:51:in
`normalize_options'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/cache/cf-uaa-lib-b1e11235dc6c/lib/uaa/token_coder.rb:158:in
`initialize'\",
\"/var/vcap/data/packages/cloud_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controller_ng/lib/vcap/uaa_token_decoder.rb:62:in
`new'\", \"/var/vcap/data/packag
es/cloud
_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controller_ng/lib/vcap/uaa_token_decoder.rb:62:in
`decode_token_with_key'\",
\"/var/vcap/data/packages/cloud_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controller_ng/lib/vcap/uaa_token_decoder.rb:53:in
`decode_token_with_asymmetric_key'\",
\"/var/vcap/data/packages/cloud_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controller_ng/lib/vcap/uaa_token_decoder.rb:29:in
`decode_token'\",
\"/var/vcap/data/packages/cloud_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controller_ng/lib/cloud_controller/security/security_context_configurer.rb:22:in
`decode_token'\",
\"/var/vcap/data/packages/cloud_controller_ng/e2284b8d57577947694deb55d61cbb3a2c87ac06.1-7f1e9cd9c57e152bf8c7a71d84131f5a43476974/cloud_controll
er_ng/li
b/cloud_controller/security/security_context_configurer.rb:10:in
`configure'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/app/controllers/base/front_controller.rb:26:in
`block in <class:FrontController>'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1610:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1610:in
`block in compile!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1014:in
`[]'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1014:in
`block in process_route'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1012:in
`catch'\", \"/var/vcap/packag
es/cloud
_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1012:in
`process_route'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:965:in
`block in filter!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:965:in
`each'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:965:in
`filter!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1083:in
`block in dispatch!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1066:in
`block in invoke'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/si
natra/ba
se.rb:1066:in `catch'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1066:in
`invoke'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1081:in
`dispatch!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:906:in
`block in call!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1066:in
`block in invoke'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1066:in
`catch'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1066:in
`invoke'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/r
uby/2.2.
0/gems/sinatra-1.4.6/lib/sinatra/base.rb:906:in `call!'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:894:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/base.r
b:49:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/nulllogger.rb:9:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/head.rb:13:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:181:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:2021:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/urlmap.rb:66:in
`block in call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/r
ack/urlm
ap.rb:50:in `each'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/request_logs.rb:21:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/vcap_request_id.rb:14:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/cors.rb:47:in
`call_app'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/cors.rb:12:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/middleware/request_metrics.rb:12:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/builder.rb:153:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/thin-1.6.3/lib/thin/connection.rb:86:in
`block in pre_process'\", \"/var/vcap/packages
/cloud_c
ontroller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/thin-1.6.3/lib/thin/connection.rb:84:in
`catch'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/thin-1.6.3/lib/thin/connection.rb:84:in
`pre_process'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/eventmachine-1.0.8/lib/eventmachine.rb:1062:in
`call'\",
\"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.2.0/gems/eventmachine-1.0.8/lib/eventmachine.rb:1062:in
`block in
spawn_threadpool'\"]}","log_level":"error","source":"cc.api","data":{"request_guid":"d44f2a12-873f-437f-7d2c-f261f503640f::1d2ea0bc-1a78-49ea-85ff-bfb9c11d2f2b"},"thread_id":47241509083720,"fiber_id":47241507190360,"process_id":5222,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/lib/sinatra/vcap.rb","lineno":53,"method":"block
in registered"}

Any thoughts on what might be causing this? I guess it could be
SSL-related or UAA related from the above, however I haven't found anything
in any other logs to explain it yet (of course, I could be looking in the
wrong place!)

Thanks
James

Join {cf-dev@lists.cloudfoundry.org to automatically receive all group messages.