bosh vms failing with http 500


jaffar.yelavalli@...
 

Hi All,
Post a sudden restart of Bosh director (due to issues with cloud provider), bosh vms command started giving http 500.
Below are some observations and logs.
Appreciate any help on this:

$ bosh vms magnolia-prod
Deployment `←[0m←[32mmagnolia-prod←[0m'
←[0m←[31mHTTP 500: ←[0m

/var/vcap/sys/log/director/error.log:
2015/05/28 13:41:12 [error] 15666#0: *6751 connect() failed (111: Connection refused) while connecting to upstream, client: 127.0.0.1, server: , request: "GET /deployments HTTP/1.1", upstream: "http://127.0.0.1:25556/deployments", host: "127.0.0.1:25555"

/var/vcap/sys/log/director/director.debug.log:
D, [2015-05-28T14:20:01.363745 #24401] [0x11d008c] DEBUG -- : (0.000160s) BEGIN
D, [2015-05-28T14:20:01.366036 #24401] [0x11d008c] DEBUG -- : (0.001031s) INSERT INTO "tasks" ("user_id", "type", "description", "state", "timestamp", "checkpoint_time") VALUES (1, 'vms', 'retrieve vm-stats', 'queued', '2015-05-28 14:20:01.362161+0000', '2015-05-28 14:20:01.362165+0000') RETURNING *
D, [2015-05-28T14:20:01.375214 #24401] [0x11d008c] DEBUG -- : (0.008387s) COMMIT
D, [2015-05-28T14:20:01.375420 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
D, [2015-05-28T14:20:01.376541 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:20:01.377447 #24401] [0x11d008c] DEBUG -- : (0.000772s) SELECT * FROM "tasks" WHERE (state NOT IN ('processing', 'queued')) ORDER BY "id" DESC LIMIT 2 OFFSET 500
D, [2015-05-28T14:20:01.378228 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
E, [2015-05-28T14:20:01.378543 #24401] [0x11d008c] ERROR -- : TypeError - can't convert nil into String:
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:1508:in `path'
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:1508:in `block in fu_list'
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:1508:in `map'
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:1508:in `fu_list'
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:619:in `rm_r'
/var/vcap/packages/ruby/lib/ruby/1.9.1/fileutils.rb:648:in `rm_rf'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/api/task_remover.rb:10:in `block in remove'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/dataset/actions.rb:152:in `block in each'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:525:in `block (2 levels) in fetch_rows'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:720:in `block in yield_hash_rows'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:714:in `times'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:714:in `yield_hash_rows'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:525:in `block in fetch_rows'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:134:in `execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:413:in `_execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:242:in `block (2 levels) in execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:425:in `check_database_errors'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:242:in `block in execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/database/connecting.rb:236:in `block in synchronize'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/connection_pool/threaded.rb:104:in `hold'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/database/connecting.rb:236:in `synchronize'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:242:in `execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/dataset/actions.rb:801:in `execute'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/adapters/postgres.rb:525:in `fetch_rows'
/var/vcap/packages/director/gem_home/gems/sequel-3.43.0/lib/sequel/dataset/actions.rb:152:in `each'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/api/task_remover.rb:9:in `remove'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/api/task_helper.rb:24:in `create_task'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/job_queue.rb:9:in `enqueue'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/api/vm_state_manager.rb:5:in `fetch_vm_state'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/lib/bosh/director/api/controllers/deployments_controller.rb:166:in `block in <class:DeploymentsController>'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1541:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1541:in `block in compile!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:950:in `[]'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:950:in `block (3 levels) in route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:966:in `route_eval'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:950:in `block (2 levels) in route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:987:in `block in process_route'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:985:in `catch'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:985:in `process_route'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:948:in `block in route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:947:in `each'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:947:in `route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1059:in `block in dispatch!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `block in invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `catch'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1056:in `dispatch!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:882:in `block in call!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `block in invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `catch'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:882:in `call!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:870:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/xss_header.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/path_traversal.rb:16:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/json_csrf.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/frame_options.rb:31:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/nulllogger.rb:9:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:175:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1949:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:929:in `forward'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1000:in `route_missing'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:961:in `route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:957:in `route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:957:in `route!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1059:in `block in dispatch!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `block in invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `catch'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1056:in `dispatch!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:882:in `block in call!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `block in invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `catch'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1041:in `invoke'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:882:in `call!'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:870:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/xss_header.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/path_traversal.rb:16:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/json_csrf.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/frame_options.rb:31:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/nulllogger.rb:9:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:175:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1949:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/xss_header.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/path_traversal.rb:16:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/json_csrf.rb:18:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/base.rb:49:in `call'
/var/vcap/packages/director/gem_home/gems/rack-protection-1.5.0/lib/rack/protection/frame_options.rb:31:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/nulllogger.rb:9:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/showexceptions.rb:21:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:175:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:1949:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/urlmap.rb:65:in `block in call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/urlmap.rb:50:in `each'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/urlmap.rb:50:in `call'
/var/vcap/packages/director/gem_home/gems/rack-1.5.2/lib/rack/commonlogger.rb:33:in `call'
/var/vcap/packages/director/gem_home/gems/sinatra-1.4.3/lib/sinatra/base.rb:212:in `call'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/connection.rb:81:in `block in pre_process'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/connection.rb:79:in `catch'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/connection.rb:79:in `pre_process'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/connection.rb:54:in `process'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/connection.rb:39:in `receive_data'
/var/vcap/packages/director/gem_home/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine'
/var/vcap/packages/director/gem_home/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/backends/base.rb:63:in `start'
/var/vcap/packages/director/gem_home/gems/thin-1.5.1/lib/thin/server.rb:159:in `start'
/var/vcap/packages/director/gem_home/gems/bosh-director-1.2559.0/bin/bosh-director:36:in `<top (required)>'
/var/vcap/packages/director/bin/bosh-director:23:in `load'
/var/vcap/packages/director/bin/bosh-director:23:in `<main>'
D, [2015-05-28T14:20:14.772521 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:20:14.773114 #24401] [0x11d008c] DEBUG -- : (0.000395s) SELECT COUNT(*) AS "count" FROM "users" LIMIT 1
D, [2015-05-28T14:20:14.773252 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
D, [2015-05-28T14:20:14.773602 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:20:14.773702 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
D, [2015-05-28T14:20:14.773807 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:20:14.774130 #24401] [0x11d008c] DEBUG -- : (0.000233s) SELECT * FROM "users" WHERE ("username" = 'admin') LIMIT 1
D, [2015-05-28T14:20:14.774246 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
D, [2015-05-28T14:21:14.799355 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:21:14.799962 #24401] [0x11d008c] DEBUG -- : (0.000394s) SELECT COUNT(*) AS "count" FROM "users" LIMIT 1
D, [2015-05-28T14:21:14.800088 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800
D, [2015-05-28T14:21:14.800423 #24401] [0x11d008c] DEBUG -- : Acquired connection: 23154800
D, [2015-05-28T14:21:14.800507 #24401] [0x11d008c] DEBUG -- : Released connection: 23154800

Let me know if any further information is required.

Thanks,
Jaffar Yelavalli

________________________________

This message is for the designated recipient only and may contain privileged, proprietary, or otherwise confidential information. If you have received it in error, please notify the sender immediately and delete the original. Any other use of the e-mail by you is prohibited. Where allowed by local law, electronic communications with Accenture and its affiliates, including e-mail and instant messaging (including content), may be scanned by our systems for the purposes of information security and assessment of internal compliance with Accenture policy.
______________________________________________________________________________________

www.accenture.com

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