error while waiting the agent when 'bosh micro deploy' on OpenStack

109 views
Skip to first unread message

bvand...@gmail.com

unread,
Aug 7, 2013, 5:31:41 AM8/7/13
to bosh-...@cloudfoundry.org
Hi
I'm new bosh user and i'm using micro bosh to install CF on OpenStack 
so as described here i'm trying to deploy bosh vm but i got an error : 

-----------------------------------------
console output
-----------------------------------------
$ bosh micro deploy ~/bosh-workspace/stemcells/latest-micro-bosh-stemcell-openstack.tgz
Deploying new micro BOSH instance `microbosh-openstack/micro_bosh.yml' to `https://microbosh-openstack:25555' (type 'yes' to continue): yes

Verifying stemcell...
File exists and readable                                     OK
Using cached manifest...
Stemcell properties                                          OK

Stemcell info
-------------
Name:    micro-bosh-stemcell
Version: 870


Deploy Micro BOSH
  unpacking stemcell (00:00:40)                                                                     
  uploading stemcell (00:56:39)                                                                     
  creating VM from d9a595bb-5db6-4b7c-83e2-c89e5ffb8e91 (00:01:38)     

Waiting for the agent               |oooooo                  | 3/11 01:06:36  ETA: 02:29:39log writing failed. can't be called from trap context
Unable to connect to Bosh agent. Check logs for more details

-----------------------------------------

(cf manifest under)

NB: the stemcell upload -image seems to be 1,2Go size - is very long : 56minutes my case.

(micro bosh client) logs :

microbosh-openstack/bosh_micro_deploy.log
(...)
HTTPClient::BadResponseError: connect to ssl proxy failed with status 503 Service Unavailable>
D, [2013-08-06T17:45:15.579426 #28122] [0x43a8f6e] DEBUG -- : Waiting for agent to be ready: #<Bosh::Agent::Error: Agent HTTP 404>
D, [2013-08-06T17:45:16.666938 #28122] [0x43a8f6e] DEBUG -- : Waiting for agent to be ready: #<Bosh::Agent::Error: Agent HTTP 404>
D, [2013-08-06T17:45:17.758981 #28122] [0x43a8f6e] DEBUG -- : Waiting for agent to be ready: #<Bosh::Agent::Error: Agent HTTP 404>
(...repeat 404 until the end...)


(bosh target vm) logs :
cf. under(...)current.txt

-----------------------------------------

Q-1: how could i diagnose and fix this error ? maybe it's a network or disk issue?
Q-2: does exists a way to validate my deployment manifest file without restarting all the process and wait the stemcell upload again ? (even if it seems a stupid question)
Q-3: how should i reproduce what deploy expect to get while waiting the agent ?


for information, here is the way i raz & restart a micro bosh deploy (Q-4 : does exist a better way?) :
       bosh micro status
       (then (A) or (B))
       ((A) bosh target vm exists )
      bosh micro delete
      cd ~/bosh-workspace/deployments && rm bosh-deployments.yml bosh_registry.log microbosh-openstack/bosh_micro_deploy.log
       ((B) bosh target vm hasn't been created; this avoid stem cell already exists error)
      cd ~/bosh-workspace/deployments && rm bosh-deployments.yml bosh_registry.log microbosh-openstack/bosh_micro_deploy.log

       bosh micro deployment microbosh-openstack
       bosh micro deploy ~/bosh-workspace/stemcells/latest-micro-bosh-stemcell-openstack.tgz
(wait one hour and pray .. ^^ )


in advance thanks
Regards
Brice




PS: sorry for the flood; my company restrict the ggdrive access so i can't attach file right here :"(


-----------------------------------------
manifest (ntp ips, url & creds have been replaced)
-----------------------------------------
~/bosh-workspace/deployments$ cat microbosh-openstack/micro_bosh.yml 

---
name: microbosh-openstack

logging:
  level: DEBUG

network:
  type: dynamic
#  vip: 10.192.36.23 # Optional  

resources:
  persistent_disk: 16384
  cloud_properties:
    instance_type: custom.m1.small

cloud:
  plugin: openstack
  properties:
    openstack:
      username: myuser
      api_key: MyApiKey
      tenant: myTenant
#      region: <region> # Optional
      default_security_groups: ["default", "microbosh"]
      default_key_name: microbosh
      private_key: ~/.ssh/microbosh/id_microbosh

apply_spec:
  properties:
    director:
      max_threads: 3
    hm:
      resurrector_enabled: true
    ntp:
        - ww.xx.yy.zz
        - ww.xx.yy.zzz


-----------------------------------------
(target vm) /var/vcap/bosh/log/current
-----------------------------------------
2013-08-07_09:00:04.10341 #[1379] INFO: Starting agent 1.5.0.pre.870...
2013-08-07_09:00:04.10367 #[1379] INFO: Configuring agent...
2013-08-07_09:00:04.10584 #[1379] INFO: Configuring instance
2013-08-07_09:00:04.12333 #[1379] INFO: OpenStack user data: "{\"registry\":{\"endpoint\":\"http://admin:admin@localhost:25889\"},\"server\":{\"name\":\"vm-c6b01d4c-5fba-4680-ab63-011e3f055027\"}}"
2013-08-07_09:00:04.12444 #[1379] INFO: failed to load infrastructure settings: Error requesting endpoint http://admin:admin@localhost:25889/instances/vm-c6b01d4c-5fba-4680-ab63-011e3f055027/settings: #<Errno::ECONNREFUSED: Connection refused - connect(2) (http://localhost:25889)>
2013-08-07_09:00:04.12496 /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/settings.rb:52:in `rescue in load_from_cache': could neither load infrastructure settings nor cached settings from: /var/vcap/bosh/settings.json (Bosh::Agent::LoadSettingsError)
2013-08-07_09:00:04.12504 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/settings.rb:47:in `load_from_cache'
2013-08-07_09:00:04.12506 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/settings.rb:29:in `rescue in load'
2013-08-07_09:00:04.12508 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/settings.rb:25:in `load'
2013-08-07_09:00:04.12510 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/settings.rb:14:in `load'
2013-08-07_09:00:04.12512 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/bootstrap.rb:61:in `load_settings'
2013-08-07_09:00:04.12514 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent/bootstrap.rb:35:in `configure'
2013-08-07_09:00:04.12515 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent.rb:106:in `start'
2013-08-07_09:00:04.12517 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/lib/bosh_agent.rb:85:in `run'
2013-08-07_09:00:04.12519 from /var/vcap/bosh/lib/ruby/gems/1.9.1/gems/bosh_agent-1.5.0.pre.870/bin/bosh_agent:102:in `<top (required)>'
2013-08-07_09:00:04.12521 from /var/vcap/bosh/bin/bosh_agent:23:in `load'
2013-08-07_09:00:04.12523 from /var/vcap/bosh/bin/bosh_agent:23:in `<main>'

(...repeat)

2013-08-07_09:00:29.85468 #[1595] INFO: Starting agent 1.5.0.pre.870...
2013-08-07_09:00:29.85493 #[1595] INFO: Configuring agent...
2013-08-07_09:00:29.85715 #[1595] INFO: Configuring instance
2013-08-07_09:00:29.87382 #[1595] INFO: OpenStack user data: "{\"registry\":{\"endpoint\":\"http://admin:admin@localhost:25889\"},\"server\":{\"name\":\"vm-c6b01d4c-5fba-4680-ab63-011e3f055027\"}}"
2013-08-07_09:00:29.91755 #[1595] INFO: loaded new infrastructure settings: {"vm"=>{"name"=>"vm-c6b01d4c-5fba-4680-ab63-011e3f055027"}, "agent_id"=>"bm-53c86613-17e4-4410-9b1d-511292c9a839", "networks"=>{"bosh"=>{"cloud_properties"=>{}, "netmask"=>nil, "gateway"=>nil, "ip"=>nil, "dns"=>nil, "type"=>"dynamic", "default"=>["dns", "gateway"]}, "vip"=>{"ip"=>"10.192.36.23", "type"=>"vip", "cloud_properties"=>{}}}, "disks"=>{"system"=>"/dev/sda", "persistent"=>{}, "ephemeral"=>"/dev/sdb"}, "env"=>{"bosh"=>{"password"=>nil}}, "ntp"=>[], "blobstore"=>{"provider"=>"local", "options"=>{"blobstore_path"=>"/var/vcap/micro_bosh/data/cache"}}, "mbus"=>"https://vcap:b00t...@0.0.0.0:6868"}
2013-08-07_09:00:29.91757 #[1595] INFO: Loaded settings: #<Bosh::Agent::Settings:0x000000017e4798 @settings={"vm"=>{"name"=>"vm-c6b01d4c-5fba-4680-ab63-011e3f055027"}, "agent_id"=>"bm-53c86613-17e4-4410-9b1d-511292c9a839", "networks"=>{"bosh"=>{"cloud_properties"=>{}, "netmask"=>nil, "gateway"=>nil, "ip"=>nil, "dns"=>nil, "type"=>"dynamic", "default"=>["dns", "gateway"]}, "vip"=>{"ip"=>"10.192.36.23", "type"=>"vip", "cloud_properties"=>{}}}, "disks"=>{"system"=>"/dev/sda", "persistent"=>{}, "ephemeral"=>"/dev/sdb"}, "env"=>{"bosh"=>{"password"=>nil}}, "ntp"=>[], "blobstore"=>{"provider"=>"local", "options"=>{"blobstore_path"=>"/var/vcap/micro_bosh/data/cache"}}, "mbus"=>"https://vcap:b00t...@0.0.0.0:6868"}, @cache_file="/var/vcap/bosh/settings.json">
2013-08-07_09:00:29.92795 #[1595] WARN: no ntp-servers configured
2013-08-07_09:00:29.95687 #[1595] INFO: Found unformatted drive
2013-08-07_09:00:29.95689 #[1595] INFO: Partition /dev/vdb
2013-08-07_09:00:29.99912 Checking that no-one is using this disk right now ...
2013-08-07_09:00:30.00192 OK
2013-08-07_09:00:30.00250 
2013-08-07_09:00:30.00250 sfdisk: ERROR: sector 0 does not have an msdos signature
2013-08-07_09:00:30.00254  /dev/vdb: unrecognized partition table type
2013-08-07_09:00:30.00262 No partitions found
2013-08-07_09:00:30.00279 Warning: no primary partition is marked bootable (active)
2013-08-07_09:00:30.00280 This does not matter for LILO, but the DOS MBR will not boot this disk.
2013-08-07_09:00:30.12010 If you created or changed a DOS partition, /dev/foo7, say, then use dd(1)
2013-08-07_09:00:30.12011 to zero the first 512 bytes:  dd if=/dev/zero of=/dev/foo7 bs=512 count=1
2013-08-07_09:00:30.12011 (See fdisk(8).)
2013-08-07_09:00:30.12786 #[1595] INFO: Create swap and data partitions
2013-08-07_09:00:30.18795 mke2fs 1.41.11 (14-Mar-2010)
2013-08-07_09:00:32.56035 #[1595] INFO: Swapon partition /dev/vdb1
2013-08-07_09:00:32.68719 #[1595] INFO: Mount data partition /dev/vdb2 to /var/vcap/data
2013-08-07_09:00:32.90676 mke2fs 1.41.11 (14-Mar-2010)
2013-08-07_09:00:33.18994 chmod: cannot access `/dev/sr0': No such file or directory
2013-08-07_09:00:33.19721 chown: cannot access `/dev/sr0': No such file or directory
2013-08-07_09:00:33.34306 #[1595] INFO: Monit: /var/vcap/bosh/etc/monitrc:8: Warning: include files not found '/var/vcap/monit/job/*.monitrc'
2013-08-07_09:00:33.34396 #[1595] INFO: Monit: monit: generated unique Monit id ff535845c2dbe437f283265bd5423859 and stored to '/root/.monit.id'
2013-08-07_09:00:33.34452 #[1595] INFO: Monit: Starting monit daemon with http interface at [127.0.0.1:2822]
2013-08-07_09:00:34.26492 #[1595] INFO: Monit Service Connection Refused: retrying
2013-08-07_09:00:34.40108 #[1595] INFO: Starting up https agent
2013-08-07_09:00:35.62216 #[1595] INFO: Message processors: {"migrate_disk"=>Bosh::Agent::Message::MigrateDisk, "list_disk"=>Bosh::Agent::Message::ListDisk, "mount_disk"=>Bosh::Agent::Message::MountDisk, "unmount_disk"=>Bosh::Agent::Message::UnmountDisk, "state"=>Bosh::Agent::Message::State, "drain"=>Bosh::Agent::Message::Drain, "apply"=>Bosh::Agent::Message::Apply, "compile_package"=>Bosh::Agent::Message::CompilePackage, "fetch_logs"=>Bosh::Agent::Message::FetchLogs, "ssh"=>Bosh::Agent::Message::Ssh, "ping"=>Bosh::Agent::Message::Ping, "noop"=>Bosh::Agent::Message::Noop, "start"=>Bosh::Agent::Message::Start, "stop"=>Bosh::Agent::Message::Stop, "prepare_network_change"=>Bosh::Agent::Message::PrepareNetworkChange, "release_apply_spec"=>Bosh::Agent::Message::ReleaseApplySpec}
2013-08-07_09:00:36.09081 >> Thin web server (v1.5.1 codename Straight Razor)
2013-08-07_09:00:36.09157 >> Maximum connections set to 1024
2013-08-07_09:00:36.09161 >> Listening on 0.0.0.0:6868, CTRL+C to stop
2013-08-07_09:00:36.23581 10.193.118.30 - - [07/Aug/2013 09:00:36] "POST  HTTP/1.1" 401 - 0.0002
2013-08-07_09:00:36.24907 10.193.118.30 - vcap [07/Aug/2013 09:00:36] "POST  HTTP/1.1" 404 507 0.0009
2013-08-07_09:00:37.36632 10.193.118.30 - - [07/Aug/2013 09:00:37] "POST  HTTP/1.1" 401 - 0.0002
2013-08-07_09:00:37.37926 10.193.118.30 - vcap [07/Aug/2013 09:00:37] "POST  HTTP/1.1" 404 507 0.0006
2013-08-07_09:00:38.49966 10.193.118.30 - - [07/Aug/2013 09:00:38] "POST  HTTP/1.1" 401 - 0.0001
2013-08-07_09:00:38.51157 10.193.118.30 - vcap [07/Aug/2013 09:00:38] "POST  HTTP/1.1" 404 507 0.0006
(repeat ..)

Ferran Rodenas

unread,
Aug 7, 2013, 9:17:23 AM8/7/13
to bosh-...@cloudfoundry.org
Is there any proxy between your local machine and the vm? The "HTTPClient::BadResponseError: connect to ssl proxy failed with status 503 Service Unavailable>" error message at the bosh_micro_deploy.log suggest that it could be a problem when cli is trying to connect to the vm agent.

- Ferdy

Brice Vandeputte

unread,
Aug 7, 2013, 9:36:09 AM8/7/13
to bosh-...@cloudfoundry.org
Thanks Ferdy for your answer
should be that ! : i had an error (wrong ip listed) in my "no_proxy" env var. 
so i remove completely all proxy-related env vars and start the deploy again,
i will reply again to give you the result (in one hour)..
sic... ^^

Brice Vandeputte

unread,
Aug 7, 2013, 10:47:57 AM8/7/13
to bosh-...@cloudfoundry.org
Ok,
i just pass the "waiting for agent step" and more but got a "connectTimeout Error" while "waiting for the director" this time. 
(volume has been created and mounted .. see below)

why can't connect to the director (if agent succes network should be ok?) ?

here is the client console :

Deploy Micro BOSH
  unpacking stemcell (00:00:41)                                                                     
  uploading stemcell (00:56:08)                                                                     
  creating VM from 5cb0d105-a55f-4df4-be47-53d4fd6f147d (00:01:34)                                  
  waiting for the agent (00:02:35)                                                                  
  create disk (00:00:01)                                                                            
  mount disk (00:00:05)                                                                             
  stopping agent services (00:00:01)                                                                
  applying micro BOSH spec (00:00:26)                                                               
  starting agent services (00:00:00)                                                                
Waiting for the director            |ooooooooooooooooooo     | 9/11 01:02:38  ETA: 00:12:37log writing failed. can't be called from trap context
/home/bvandeputte/.rvm/gems/ruby-2.0.0-p247/gems/httpclient-2.2.4/lib/httpclient/session.rb:775:in `initialize': execution expired (HTTPClient::ConnectTimeoutError)
from /home/bvandeputte/.rvm/gems/ruby-2.0.0-p247/gems/httpclient-2.2.4/lib/httpclient/session.rb:775:in `new'
from /home/bvandeputte/.rvm/gems/ruby-2.0.0-p247/gems/httpclient-2.2.4/lib/httpclient/session.rb:775:in `create_socket'

client detailled logs :

D, [2013-08-07T16:31:16.966899 #2404] [create_vm(bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77, ...)] DEBUG -- : Waiting for Server `e1475291-96df-4197-8b3d-38a30e4166f6' to be active (90.054624961s)
I, [2013-08-07T16:31:17.051770 #2404] [create_vm(bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77, ...)]  INFO -- : Server `e1475291-96df-4197-8b3d-38a30e4166f6' is now active, took 90.139525968s
I, [2013-08-07T16:31:17.052079 #2404] [create_vm(bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77, ...)]  INFO -- : Configuring network for server `e1475291-96df-4197-8b3d-38a30e4166f6'...
I, [2013-08-07T16:31:17.103302 #2404] [create_vm(bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77, ...)]  INFO -- : Associating server `e1475291-96df-4197-8b3d-38a30e4166f6' with floating IP `10.192.36.23'
I, [2013-08-07T16:31:19.872097 #2404] [create_vm(bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77, ...)]  INFO -- : Updating settings for server `e1475291-96df-4197-8b3d-38a30e4166f6'...
I, [2013-08-07T16:31:20.396554 #2404] [0x4588f6e]  INFO -- : discovered bosh ip=10.192.36.23
D, [2013-08-07T16:32:23.501867 #2404] [0x4588f6e] DEBUG -- : tcp socket 10.192.36.23:22 SystemCallError: #<Errno::ETIMEDOUT: Connection timed out - connect(2)>
D, [2013-08-07T16:32:24.560709 #2404] [0x4588f6e] DEBUG -- : tcp socket 10.192.36.23:22 is readable
I, [2013-08-07T16:33:24.561602 #2404] [0x4588f6e]  INFO -- : Starting SSH session for port forwarding to vc...@10.192.36.23...
D, [2013-08-07T16:33:25.168563 #2404] [0x4588f6e] DEBUG -- : ssh vc...@10.192.36.23: ESTABLISHED
I, [2013-08-07T16:33:25.169990 #2404] [0x4588f6e]  INFO -- : SSH forwarding for port 25889 started: OK
D, [2013-08-07T16:33:25.171555 #2404] [0x4588f6e] DEBUG -- : Waiting for agent to be ready: nil
D, [2013-08-07T16:33:56.180251 #2404] [0x4588f6e] DEBUG -- : Waiting for agent to be ready: #<Bosh::Agent::Error: Request details:
payload: {"method":"ping","arguments":[],"reply_to":"bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77"}
user: vcap
password: b00tstrap
HTTPClient::ConnectTimeoutError: execution expired>
I, [2013-08-07T16:33:56.455074 #2404] [create_disk(16384, e1475291-96df-4197-8b3d-38a30e4166f6)]  INFO -- : Creating new volume...
I, [2013-08-07T16:33:56.645303 #2404] [create_disk(16384, e1475291-96df-4197-8b3d-38a30e4166f6)]  INFO -- : Creating new volume `9c54994a-e8ad-482e-9313-2e3926293ca9'...
D, [2013-08-07T16:33:56.646691 #2404] [create_disk(16384, e1475291-96df-4197-8b3d-38a30e4166f6)] DEBUG -- : Waiting for Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to be available (3.8681e-05s)
D, [2013-08-07T16:33:57.800061 #2404] [create_disk(16384, e1475291-96df-4197-8b3d-38a30e4166f6)] DEBUG -- : Waiting for Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to be available (1.153375853s)
I, [2013-08-07T16:33:57.897217 #2404] [create_disk(16384, e1475291-96df-4197-8b3d-38a30e4166f6)]  INFO -- : Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' is now available, took 1.250561284s
I, [2013-08-07T16:33:58.075595 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)]  INFO -- : Attaching volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to server `e1475291-96df-4197-8b3d-38a30e4166f6'...
I, [2013-08-07T16:33:58.202361 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)]  INFO -- : Attaching volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to server `e1475291-96df-4197-8b3d-38a30e4166f6', device name is `/dev/sdc'
D, [2013-08-07T16:33:58.465042 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)] DEBUG -- : Waiting for Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to be in-use (3.5787e-05s)
D, [2013-08-07T16:33:59.534491 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)] DEBUG -- : Waiting for Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' to be in-use (1.069451995s)
I, [2013-08-07T16:33:59.605484 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)]  INFO -- : Volume `9c54994a-e8ad-482e-9313-2e3926293ca9' is now in-use, took 1.140484856s
I, [2013-08-07T16:33:59.606329 #2404] [attach_disk(e1475291-96df-4197-8b3d-38a30e4166f6, 9c54994a-e8ad-482e-9313-2e3926293ca9)]  INFO -- : Updating settings for server `e1475291-96df-4197-8b3d-38a30e4166f6'...
D, [2013-08-07T16:34:32.699003 #2404] [0x4588f6e] DEBUG -- : Waiting for director to be ready: nil


target vm logs :
 nothing special into /var/vcap/sys/log/director/director*.log

D, [2013-08-07T14:39:50.544234 #2752] [0x131e074] DEBUG -- : (0.000174s) SELECT * FROM "deployments" ORDER BY "name" ASC
D, [2013-08-07T14:39:50.544289 #2752] [0x131e074] DEBUG -- : Released connection: 26866820
D, [2013-08-07T14:40:50.558060 #2752] [0x131e074] DEBUG -- : Acquired connection: 26866820
D, [2013-08-07T14:40:50.558618 #2752] [0x131e074] DEBUG -- : (0.000407s) SELECT COUNT(*) AS "count" FROM "users" LIMIT 1
D, [2013-08-07T14:40:50.558694 #2752] [0x131e074] DEBUG -- : Released connection: 26866820
D, [2013-08-07T14:40:50.558867 #2752] [0x131e074] DEBUG -- : Acquired connection: 26866820
D, [2013-08-07T14:40:50.559062 #2752] [0x131e074] DEBUG -- : (0.000140s) SELECT * FROM "deployments" ORDER BY "name" ASC
D, [2013-08-07T14:40:50.559114 #2752] [0x131e074] DEBUG -- : Released connection: 26866820
vcap@bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77:~$ cat /var/vcap/sys/log/director/director.stdout.log 
vcap@bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77:~$ cat /var/vcap/sys/log/director/director.stderr.log 
172.16.32.10 - - [07/Aug/2013 14:34:50] "GET /deployments HTTP/1.0" 200 2 0.0244
172.16.32.10 - - [07/Aug/2013 14:35:50] "GET /deployments HTTP/1.0" 200 2 0.0027
172.16.32.10 - - [07/Aug/2013 14:36:50] "GET /deployments HTTP/1.0" 200 2 0.0023
172.16.32.10 - - [07/Aug/2013 14:37:50] "GET /deployments HTTP/1.0" 200 2 0.0022
172.16.32.10 - - [07/Aug/2013 14:38:50] "GET /deployments HTTP/1.0" 200 2 0.0022
172.16.32.10 - - [07/Aug/2013 14:39:50] "GET /deployments HTTP/1.0" 200 2 0.0023
172.16.32.10 - - [07/Aug/2013 14:40:50] "GET /deployments HTTP/1.0" 200 2 0.0021
172.16.32.10 - - [07/Aug/2013 14:41:50] "GET /deployments HTTP/1.0" 200 2 0.0041

 end of bosh/current seems normal too :

2013-08-07_14:34:29.63703 10.194.3.123 - - [07/Aug/2013 14:34:29] "POST /agent HTTP/1.1" 401 - 0.0003
2013-08-07_14:34:29.64892 #[2006] INFO: Message: {"method"=>"get_task", "arguments"=>["e13f9c76-0104-4c75-8c8e-4aba5aada2c0"], "reply_to"=>"bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77"}
2013-08-07_14:34:29.64963 10.194.3.123 - vcap [07/Aug/2013 14:34:29] "POST /agent HTTP/1.1" 200 85 0.0013
2013-08-07_14:34:30.76327 10.194.3.123 - - [07/Aug/2013 14:34:30] "POST /agent HTTP/1.1" 401 - 0.0003
2013-08-07_14:34:30.77575 #[2006] INFO: Message: {"method"=>"get_task", "arguments"=>["e13f9c76-0104-4c75-8c8e-4aba5aada2c0"], "reply_to"=>"bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77"}
2013-08-07_14:34:30.77576 10.194.3.123 - vcap [07/Aug/2013 14:34:30] "POST /agent HTTP/1.1" 200 6328 0.0013
2013-08-07_14:34:30.83640 10.194.3.123 - - [07/Aug/2013 14:34:30] "POST /agent HTTP/1.1" 401 - 0.0002
2013-08-07_14:34:30.88848 #[2006] INFO: Message: {"method"=>"start", "arguments"=>[], "reply_to"=>"bm-2e5bc6fa-bab5-47c1-b701-2581251b0e77"}
2013-08-07_14:34:30.90689 #[2006] DEBUG: Requesting 'start' for nats
2013-08-07_14:34:30.91296 #[2006] DEBUG: Requesting 'start' for redis
2013-08-07_14:34:30.91411 #[2006] DEBUG: Requesting 'start' for postgres
2013-08-07_14:34:30.91508 #[2006] DEBUG: Requesting 'start' for powerdns
2013-08-07_14:34:30.91571 #[2006] DEBUG: Requesting 'start' for blobstore_nginx
2013-08-07_14:34:30.91644 #[2006] DEBUG: Requesting 'start' for director
2013-08-07_14:34:30.91815 #[2006] DEBUG: Requesting 'start' for worker_1
2013-08-07_14:34:30.91908 #[2006] DEBUG: Requesting 'start' for worker_2
2013-08-07_14:34:30.91997 #[2006] DEBUG: Requesting 'start' for worker_3
2013-08-07_14:34:30.92103 #[2006] DEBUG: Requesting 'start' for director_scheduler
2013-08-07_14:34:30.92198 #[2006] DEBUG: Requesting 'start' for director_nginx
2013-08-07_14:34:30.92297 #[2006] DEBUG: Requesting 'start' for registry
2013-08-07_14:34:30.92397 #[2006] DEBUG: Requesting 'start' for health_monitor
2013-08-07_14:34:31.02009 10.194.3.123 - vcap [07/Aug/2013 14:34:31] "POST /agent HTTP/1.1" 200 20 0.1271

where should i search?

thanks
regards
Brice

Ferran Rodenas

unread,
Aug 7, 2013, 11:02:54 AM8/7/13
to bosh-...@cloudfoundry.org
Try the next step (Testing your Micro BOSH). If it doesn't work, check:

1) That you can ping your microBOSH vm from your local machine: ping 10.192.36.23
2) That the microBOSH vm security group includes port 25555 (or telnet 10.192.36.23 25555).


- Ferdy


2013/8/7 Brice Vandeputte <bvand...@gmail.com>

Brice Vandeputte

unread,
Aug 7, 2013, 11:19:57 AM8/7/13
to bosh-...@cloudfoundry.org
ok for the ping and the telnet
ok for the next step too (create user and status)
(strange end any way for the connect timeout..)

tomorrow i will install CF
but i think i could close this thread

thanks for your help ^^
regards
Brice
Reply all
Reply to author
Forward
0 new messages