rabbitmq warden.log

gistfile1.txt

==> /var/vcap/sys/log/rabbit_node/rabbit_node.log <==
[2013-07-24 08:53:15.048611] rabbit_node_100_0 - pid=25703 tid=0d3c fid=d169  DEBUG -- RMQaaS-Node: Provision request: {"plan":"100","version":"2.8"} from _INBOX.298145f800980be9d074601af4
[2013-07-24 08:53:15.049244] rabbit_node_100_0 - pid=25703 tid=0d3c fid=d169  DEBUG -- RMQaaS-Node: Provision Request Details - plan=100, credentials=, version=2.8

==> /var/vcap/sys/log/rabbit_gateway/rabbit_gateway.log <==
[2013-07-24 08:53:15.044394] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- Provision request for label=rabbitmq-2.8, plan=100, version=2.8
[2013-07-24 08:53:15.044935] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- [RMQaaS-Provisioner] Attempting to provision instance (request={:label=>"rabbitmq-2.8", :name=>"rabbitmq-a8220", :email=>"admin", :plan=>"100", :plan_option=>{}, :version=>"2.8", :provider=>"core", :space_guid=>"d5dbf0e6-5a6f-40da-9
341-f1879d7716b8", :organization_guid=>"6d56d655-6a8c-4ba0-ba38-5a6b1ae6eef3", :unique_id=>"core_rabbitmq_100"})
[2013-07-24 08:53:15.045690] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- [RMQaaS-Provisioner] Picking version nodes from the following 1 '100' plan nodes: [{"available_capacity"=>150, "capacity_unit"=>1, "id"=>"rabbit_node_100_0", "plan"=>"100", "supported_versions"=>["2.8"], "time"=>1374655985}]
[2013-07-24 08:53:15.046255] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- [RMQaaS-Provisioner] 1 nodes allow provisioning for version: 2.8
[2013-07-24 08:53:15.046593] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- [RMQaaS-Provisioner] Provisioning on rabbit_node_100_0

==> /var/vcap/sys/log/rabbit/warden/warden.log <==
{"timestamp":1374655996.1948087,"message":"Container created","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":26827480,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/linux.rb","lineno":104,"method":"do_create"}
{"timestamp":1374655996.4110365,"message":"Container started","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":26827480,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/linux.rb","lineno":11
0,"method":"do_create"}
{"timestamp":1374655996.4117615,"message":"Wrote snapshot in 0.000408","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":26827480,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374655996.412031,"message":"create (took 0.527490)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"bind_mounts":["#<Warden::Protocol::CreateRequest::BindMount:0x00000002f94848>","#<Warden::Protocol::CreateRequest::BindMount:0x00000002f93d58>","#<Warde
n::Protocol::CreateRequest::BindMount:0x00000003328400>","#<Warden::Protocol::CreateRequest::BindMount:0x00000003327960>","#<Warden::Protocol::CreateRequest::BindMount:0x00000003326ec0>","#<Warden::Protocol::CreateRequest::BindMount:0x000000033264c0>"]},"response":{"handle":"1726rgesqil"}},"thread_id":19681420,"fib
er_id":26827480,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.41939,"message":"Wrote snapshot in 0.000402","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":26958840,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","line
no":360,"method":"write_snapshot"}
{"timestamp":1374655996.419816,"message":"spawn (took 0.005148)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","script":"chown -R vcap:vcap /var/vcap/sys/log/monit /var/vcap/store/rabbit/instances/1c4db1e3-91ad-4160-89dd-052029728985 /var/vca
p/sys/service-log/rabbit/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap/data/packages/erlang/0.1-dev.1","privileged":true},"response":{"job_id":13}},"thread_id":19681420,"fiber_id":26958840,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,
"method":"dispatch"}
{"timestamp":1374655996.4796839,"message":"Wrote snapshot in 0.000536","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":27314980,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374655996.4809873,"message":"link (took 0.060635)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","job_id":13},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":19681420,"fiber_id":26958840,"process_id":25572,"fil
e":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.4819763,"message":"run (took 0.067406)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","script":"chown -R vcap:vcap /var/vcap/sys/log/monit /var/vcap/store/rabbit/instances/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap
/sys/service-log/rabbit/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap/data/packages/erlang/0.1-dev.1","privileged":true},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":19681420,"fiber_id":26958840,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/conta
iner/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.5041244,"message":"Wrote snapshot in 0.000519","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":19581900,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
{"timestamp":1374655996.5046484,"message":"limit_bandwidth (took 0.020094)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","rate":10485,"burst":10485},"response":{"rate":10485,"burst":10485}},"thread_id":19681420,"fiber_id":19581900,"process_i
d":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.5116057,"message":"Wrote snapshot in 0.000459","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":20845140,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374655996.512147,"message":"spawn (took 0.005533)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","script":"/var/vcap/store/rabbitmq_common/bin/warden_service_ctl start /var/vcap/store/rabbit/instances/1c4db1e3-91ad-4160-89dd-052
029728985 /var/vcap/sys/service-log/rabbit/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap/store/rabbitmq_common /var/vcap/packages/rabbitmq-2.8 /var/vcap/data/packages/erlang/0.1-dev.1 1c4db1e3-91ad-4160-89dd-052029728985"},"response":{"job_id":14}},"thread_id":19681420,"fiber_id":20845140,"process_id":25572,"file"
:"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.5320137,"message":"Wrote snapshot in 0.000502","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":21619700,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374655996.5326073,"message":"net_in (took 0.018395)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","host_port":15005,"container_port":10001},"response":{"host_port":15005,"container_port":10001}},"thread_id":19681420,"fiber_id":
21619700,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374655996.5447958,"message":"Exited with status 1 (0.035s): [[\"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/src/closefds/closefds\", \"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/src/closefds/closefds\"], \"/var/vcap/store/rabbit/containers/1726rgesqil/bin/iomux-link\", \"-w\",
 \"/var/vcap/store/rabbit/containers/1726rgesqil/jobs/14/cursors\", \"/var/vcap/store/rabbit/containers/1726rgesqil/jobs/14\"]","log_level":"warn","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","stdout":"","stderr":""},"thread_id":19681420,"fiber_id":27314980,"process_id":25572,"file":"/var/vcap
/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/spawn.rb","lineno":134,"method":"set_deferred_success"}
{"timestamp":1374655996.5458493,"message":"Wrote snapshot in 0.000559","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":27314980,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374655996.5655348,"message":"info (took 0.030904)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil"},"response":{"state":"active","events":[],"host_ip":"10.254.0.17","container_ip":"10.254.0.18","container_path":"/var/vcap/store/ra
bbit/containers/1726rgesqil","memory_stat":"#<Warden::Protocol::InfoResponse::MemoryStat:0x00000002c1a640>","cpu_stat":"#<Warden::Protocol::InfoResponse::CpuStat:0x00000002c4fcc8>","bandwidth_stat":"#<Warden::Protocol::InfoResponse::BandwidthStat:0x00000002cdc5b0>","job_ids":[14]}},"thread_id":19681420,"fiber_id":2
2755960,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}

==> /var/vcap/sys/log/rabbit_node/rabbit_node.log <==
[2013-07-24 08:53:21.637165] rabbit_node_100_0 - pid=25703 tid=0d3c fid=d169  ERROR -- Error provision instance: Error Code: 30503, Error Message: Service start timeout

==> /var/vcap/sys/log/rabbit/warden/warden.log <==
{"timestamp":1374656001.6792905,"message":"info (took 0.040152)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil"},"response":{"state":"active","events":[],"host_ip":"10.254.0.17","container_ip":"10.254.0.18","container_path":"/var/vcap/store/ra
bbit/containers/1726rgesqil","memory_stat":"#<Warden::Protocol::InfoResponse::MemoryStat:0x00000002cf6ac8>","cpu_stat":"#<Warden::Protocol::InfoResponse::CpuStat:0x000000033a8d30>","bandwidth_stat":"#<Warden::Protocol::InfoResponse::BandwidthStat:0x00000003640c78>","job_ids":[]}},"thread_id":19681420,"fiber_id":235
70560,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374656001.6901102,"message":"Wrote snapshot in 0.000488","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":27433040,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374656001.6906521,"message":"spawn (took 0.005756)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","script":"/var/vcap/store/rabbitmq_common/bin/warden_service_ctl stop /var/vcap/store/rabbit/instances/1c4db1e3-91ad-4160-89dd-052
029728985 /var/vcap/sys/service-log/rabbit/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap/store/rabbitmq_common"},"response":{"job_id":15}},"thread_id":19681420,"fiber_id":27433040,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":
"dispatch"}
{"timestamp":1374656001.7100954,"message":"Wrote snapshot in 0.000523","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":27314980,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374656001.7105415,"message":"link (took 0.019337)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","job_id":15},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":19681420,"fiber_id":27433040,"process_id":25572,"fil
e":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374656001.7111864,"message":"run (took 0.026385)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil","script":"/var/vcap/store/rabbitmq_common/bin/warden_service_ctl stop /var/vcap/store/rabbit/instances/1c4db1e3-91ad-4160-89dd-05202
9728985 /var/vcap/sys/service-log/rabbit/1c4db1e3-91ad-4160-89dd-052029728985 /var/vcap/store/rabbitmq_common"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":19681420,"fiber_id":27433040,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.
rb","lineno":318,"method":"dispatch"}
{"timestamp":1374656001.7450325,"message":"Wrote snapshot in 0.000725","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":25519340,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/base.rb","li
neno":360,"method":"write_snapshot"}
{"timestamp":1374656001.7458556,"message":"stop (took 0.032524)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil"},"response":{}},"thread_id":19681420,"fiber_id":25519340,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.
1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
{"timestamp":1374656001.8678238,"message":"Container destroyed","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil"},"thread_id":19681420,"fiber_id":24920520,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-dev.1/warden/lib/warden/container/linux.rb","lineno":
129,"method":"do_destroy"}
{"timestamp":1374656001.8683991,"message":"destroy (took 0.120479)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"1726rgesqil","request":{"handle":"1726rgesqil"},"response":{}},"thread_id":19681420,"fiber_id":24920520,"process_id":25572,"file":"/var/vcap/data/packages/rabbit_node_ng/0.1-d
ev.1/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}

==> /var/vcap/sys/log/rabbit_node/rabbit_node.log <==
[2013-07-24 08:53:22.091994] rabbit_node_100_0 - pid=25703 tid=0d3c fid=d169   WARN -- Exception at on_provision Error Code: 30503, Error Message: Service start timeout

==> /var/vcap/sys/log/rabbit_gateway/rabbit_gateway.log <==
[2013-07-24 08:53:22.096128] rabbit_gateway - pid=23493 tid=c017 fid=b776  DEBUG -- Reply status:500, headers:{"Content-Type"=>"application/json"}, body:{"code":30503,"description":"Service start timeout"}

Hi, Did you resolve this issue?

I have opened a bug against the project to try to work through it, any help would be appreciated.
cloudfoundry-community-attic/cf-services-contrib-release#93

Thanks,
Troy.