Attachment 713581 Details for Bug 921902 – development.log from /var/log/openshift/broker

development.log from /var/log/openshift/broker

development.log (text/x-log), 61.30 KB, created by Mengjiao Gao on 2013-03-21 03:19:54 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Mengjiao Gao

Created: 2013-03-21 03:19:54 UTC

Size: 61.30 KB

patch

obsolete

>2013-03-20 23:18:04.530 [INFO ] Started GET "/broker/rest/domains/dev/applications/kit.json" for 127.0.0.1 at 2013-03-20 23:18:04 -0400 (pid:25429)
>2013-03-20 23:18:04.534 [INFO ] Processing by ApplicationsController#show as JSON (pid:25429)
>2013-03-20 23:18:04.534 [INFO ] Parameters: {"domain_id"=>"dev", "id"=>"kit"} (pid:25429)
>2013-03-20 23:18:04.622 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"7b4ab64020c55d54bc6fe0ee444373591d8beb89c0e5dee4cfb3ef385ddd864d"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (9.0072ms) (pid:25429)
>2013-03-20 23:18:04.629 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7a9fe491f57f4e000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (4.5824ms) (pid:25429)
>2013-03-20 23:18:04.635 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7a9fe491f57f4e000001 LOGIN=mgao+dev2000@redhat.com IP=127.0.0.1 SCOPES=session Authenticated (pid:25429)
>2013-03-20 23:18:04.641 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"owner_id"=>"514a7a9fe491f57f4e000001", "canonical_namespace"=>"dev"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.8469ms) (pid:25429)
>2013-03-20 23:18:04.647 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"domain_id"=>"514a7adce491f51dc3000002", "canonical_name"=>"kit"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (4.6017ms) (pid:25429)
>2013-03-20 23:18:04.649 [DEBUG] Dalli::Server#connect localhost:11212 (pid:25429)
>2013-03-20 23:18:04.655 [INFO ] localhost:11212 failed (count: 14) (pid:25429)
>2013-03-20 23:18:04.656 [DEBUG] localhost:11212 is still down (for 309.415 seconds now) (pid:25429)
>2013-03-20 23:18:04.694 [DEBUG] SUCCESS ACTION=SHOW_APPLICATION USER_ID=514a7a9fe491f57f4e000001 LOGIN=mgao+dev2000@redhat.com APP=kit DOMAIN=dev APP_UUID=621d1bd891d511e2a43412313d0439e5 Application 'kit' found (pid:25429)
>2013-03-20 23:18:04.697 [INFO ] Completed 200 OK in 163ms (Views: 0.8ms) (pid:25429)
>2013-03-20 23:18:04.742 [INFO ] Started GET "/broker/rest/cartridges.json" for 127.0.0.1 at 2013-03-20 23:18:04 -0400 (pid:25429)
>2013-03-20 23:18:04.743 [INFO ] Processing by CartridgesController#index as JSON (pid:25429)
>2013-03-20 23:18:04.744 [DEBUG] down_retry_delay not reached for localhost:11212 (0.912 seconds left) (pid:25429)
>2013-03-20 23:18:04.753 [DEBUG] down_retry_delay not reached for localhost:11212 (0.903 seconds left) (pid:25429)
>2013-03-20 23:18:04.758 [DEBUG] down_retry_delay not reached for localhost:11212 (0.898 seconds left) (pid:25429)
>2013-03-20 23:18:04.760 [DEBUG] SUCCESS ACTION=LIST_CARTRIDGES USER_ID= LOGIN= List all cartridges (pid:25429)
>2013-03-20 23:18:04.830 [INFO ] Completed 200 OK in 87ms (Views: 61.0ms) (pid:25429)
>2013-03-20 23:18:05.200 [DEBUG] down_retry_delay not reached for localhost:11212 (0.456 seconds left) (pid:25429)
>2013-03-20 23:18:05.200 [INFO ] Started POST "/broker/rest/domains/dev/applications/kit/cartridges.json" for 127.0.0.1 at 2013-03-20 23:18:05 -0400 (pid:25429)
>2013-03-20 23:18:05.203 [INFO ] Processing by EmbCartController#create as JSON (pid:25429)
>2013-03-20 23:18:05.203 [INFO ] Parameters: {"name"=>"switchyard-0.6", "domain_id"=>"dev", "application_id"=>"kit", "emb_cart"=>{"name"=>"switchyard-0.6"}} (pid:25429)
>2013-03-20 23:18:05.207 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"7b4ab64020c55d54bc6fe0ee444373591d8beb89c0e5dee4cfb3ef385ddd864d"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.6917ms) (pid:25429)
>2013-03-20 23:18:05.209 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7a9fe491f57f4e000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.3557ms) (pid:25429)
>2013-03-20 23:18:05.212 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7a9fe491f57f4e000001 LOGIN=mgao+dev2000@redhat.com IP=127.0.0.1 SCOPES=session Authenticated (pid:25429)
>2013-03-20 23:18:05.214 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"owner_id"=>"514a7a9fe491f57f4e000001", "canonical_namespace"=>"dev"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (1.3120ms) (pid:25429)
>2013-03-20 23:18:05.218 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"domain_id"=>"514a7adce491f51dc3000002", "canonical_name"=>"kit"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (2.8145ms) (pid:25429)
>2013-03-20 23:18:05.220 [DEBUG] down_retry_delay not reached for localhost:11212 (0.436 seconds left) (pid:25429)
>2013-03-20 23:18:05.234 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"514a7adce491f51dc3000002"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (5.6486ms) (pid:25429)
>2013-03-20 23:18:05.242 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514a7a9fe491f57f4e000001", "$or"=>[{"app_ids.514a7afbe491f5fca7000002"=>{"$exists"=>false}}, {"app_ids.514a7afbe491f5fca7000002"=>{"$lt"=>1363835885}}]}, :new=>true, :update=>{"$set"=>{"app_ids.514a7afbe491f5fca7000002"=>1363836485}}} (6.3889ms) (pid:25429)
>2013-03-20 23:18:05.256 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$push"=>{"pending_op_groups"=>{"_id"=>"514a7bede491f5fca7000038", "num_gears_added"=>0, "num_gears_removed"=>0, "num_gears_created"=>0, "num_gears_destroyed"=>0, "num_gears_rolled_back"=>0, "user_agent"=>nil, "op_type"=>:add_features, "args"=>{"features"=>["switchyard-0.6"], "group_overrides"=>[], "init_git_url"=>nil}, "parent_op_id"=>nil, "updated_at"=>2013-03-21 03:18:05 UTC, "created_at"=>2013-03-21 03:18:05 UTC}}} flags=[] (pid:25429)
>2013-03-20 23:18:05.256 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (6.1824ms) (pid:25429)
>2013-03-20 23:18:05.260 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"514a7afbe491f5fca7000002"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (3.0227ms) (pid:25429)
>2013-03-20 23:18:05.320 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"514a7adce491f51dc3000002"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.6037ms) (pid:25429)
>2013-03-20 23:18:05.324 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7a9fe491f57f4e000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (2.4078ms) (pid:25429)
>2013-03-20 23:18:05.327 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"514a7a9fe491f57f4e000001"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.5546ms) (pid:25429)
>2013-03-20 23:18:05.331 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514a7a9fe491f57f4e000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x00000005e3ca38>"=>1363835885}], "app_ids.514a7afbe491f5fca7000002"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1363836485}}} (2.4683ms) (pid:25429)
>2013-03-20 23:18:05.332 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"514a7a9fe491f57f4e000001"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.4408ms) (pid:25429)
>2013-03-20 23:18:05.344 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$pushAll"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"514a7bede491f5fca700003a", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, {"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}], "min_gears"=>1, "max_gears"=>1}]}}, {"_id"=>"514a7bede491f5fca7000039", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}}, "prereq"=>[nil]}, {"_id"=>"514a7bede491f5fca700003b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "gear_id"=>"514a7afbe491f5fca7000002", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}, "init_git_url"=>nil}, "prereq"=>["514a7bede491f5fca7000039", []]}, {"_id"=>"514a7bede491f5fca700003c", "state"=>:init, "retry_count"=>0, "saved_values"=>{:connections=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "prereq"=>["514a7bede491f5fca700003a", "514a7bede491f5fca7000039", "514a7bede491f5fca700003b"]}, {"_id"=>"514a7bede491f5fca700003d", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["514a7bede491f5fca700003c"]}]}} flags=[] (pid:25429)
>2013-03-20 23:18:05.344 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (3.5050ms) (pid:25429)
>2013-03-20 23:18:05.361 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514a7a9fe491f57f4e000001", "locked"=>true, "app_ids.514a7afbe491f5fca7000002"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (2.3992ms) (pid:25429)
>2013-03-20 23:18:05.364 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"514a7afbe491f5fca7000002"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.9694ms) (pid:25429)
>2013-03-20 23:18:05.388 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"514a7bede491f5fca700003a", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, {"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}], "min_gears"=>1, "max_gears"=>1}]}}, {"_id"=>"514a7bede491f5fca7000039", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}}, "prereq"=>[nil]}, {"_id"=>"514a7bede491f5fca700003b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "gear_id"=>"514a7afbe491f5fca7000002", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}, "init_git_url"=>nil}, "prereq"=>["514a7bede491f5fca7000039", []]}, {"_id"=>"514a7bede491f5fca700003c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "prereq"=>["514a7bede491f5fca700003a", "514a7bede491f5fca7000039", "514a7bede491f5fca700003b"]}, {"_id"=>"514a7bede491f5fca700003d", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["514a7bede491f5fca700003c"]}]}} flags=[] (pid:25429)
>2013-03-20 23:18:05.391 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (6.2888ms) (pid:25429)
>2013-03-20 23:18:05.399 [DEBUG] Execute set_group_overrides (pid:25429)
>2013-03-20 23:18:05.443 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, {"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}], "min_gears"=>1, "max_gears"=>1}], "updated_at"=>2013-03-21 03:18:05 UTC}} flags=[] (pid:25429)
>2013-03-20 23:18:05.444 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.3065ms) (pid:25429)
>2013-03-20 23:18:05.446 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:completed}} flags=[] (pid:25429)
>2013-03-20 23:18:05.447 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.4088ms) (pid:25429)
>2013-03-20 23:18:05.448 [DEBUG] Execute new_component (pid:25429)
>2013-03-20 23:18:05.451 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$push"=>{"component_instances"=>{"_id"=>"514a7bede491f5fca700003e", "component_properties"=>{}, "cartridge_name"=>"switchyard-0.6", "component_name"=>"switchyard-0.6", "group_instance_id"=>"514a7afce491f5fca7000010"}}} flags=[] (pid:25429)
>2013-03-20 23:18:05.451 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5937ms) (pid:25429)
>2013-03-20 23:18:05.453 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:completed}} flags=[] (pid:25429)
>2013-03-20 23:18:05.453 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.2884ms) (pid:25429)
>2013-03-20 23:18:05.455 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"514a7afbe491f5fca7000002"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.9773ms) (pid:25429)
>2013-03-20 23:18:05.467 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"514a7bede491f5fca700003a", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, {"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "state"=>:completed}, {"_id"=>"514a7bede491f5fca7000039", "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}}, "op_type"=>:new_component, "prereq"=>[nil], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"514a7bede491f5fca700003b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "gear_id"=>"514a7afbe491f5fca7000002", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}, "init_git_url"=>nil}, "prereq"=>["514a7bede491f5fca7000039", []]}, {"_id"=>"514a7bede491f5fca700003c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "prereq"=>["514a7bede491f5fca700003a", "514a7bede491f5fca7000039", "514a7bede491f5fca700003b"]}, {"_id"=>"514a7bede491f5fca700003d", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["514a7bede491f5fca700003c"]}]}} flags=[] (pid:25429)
>2013-03-20 23:18:05.467 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.7151ms) (pid:25429)
>2013-03-20 23:18:05.477 [DEBUG] Execute add_component (pid:25429)
>2013-03-20 23:18:05.486 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x0000000625e260> (pid:25429)
>2013-03-20 23:18:05.490 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"switchyard-0.6", :action=>"configure", :args=>{"--with-app-uuid"=>"621d1bd891d511e2a43412313d0439e5", "--with-app-name"=>"kit", "--with-container-uuid"=>"62c63c7c91d511e2a43412313d0439e5", "--with-container-name"=>"kit", "--with-namespace"=>"dev", "--with-request-id"=>"c167c0f4f1c1b3b95a8c0a91a3fd8bfb", "--cart-name"=>"switchyard-0.6"}}, ip-10-114-70-19, {'identity' => ip-10-114-70-19}) (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:08.433 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000032b62b0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-114-70-19", :statuscode=>1, :statusmsg=>"cartridge_do_action failed -1. Output Control action 'configure' returned an error. rc=2\nTransformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist\n", :data=>{:time=>nil, :output=>"Control action 'configure' returned an error. rc=2\nTransformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist\n", :exitcode=>-1}}>] (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:08.436 [DEBUG] DEBUG: MCollective Response Time (execute_direct: configure): 2.954206761s  (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:08.436 [DEBUG] DEBUG: server results: Control action 'configure' returned an error. rc=2 (pid:25429)
>2013-03-20 23:18:08.436 [DEBUG] DEBUG: server results: Transformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist (pid:25429)
>2013-03-20 23:18:08.437 [DEBUG] DEBUG: Failed to embed 'switchyard-0.6' in 'kit' for user 'mgao+dev2000@redhat.com' (pid:25429)
>2013-03-20 23:18:08.441 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x000000045565a0> (pid:25429)
>2013-03-20 23:18:08.441 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"switchyard-0.6", :action=>"deconfigure", :args=>{"--with-app-uuid"=>"621d1bd891d511e2a43412313d0439e5", "--with-app-name"=>"kit", "--with-container-uuid"=>"62c63c7c91d511e2a43412313d0439e5", "--with-container-name"=>"kit", "--with-namespace"=>"dev", "--with-request-id"=>"c167c0f4f1c1b3b95a8c0a91a3fd8bfb", "--cart-name"=>"switchyard-0.6"}}, ip-10-114-70-19, {'identity' => ip-10-114-70-19}) (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:10.213 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000004ae9d28 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-114-70-19", :statuscode=>1, :statusmsg=>"cartridge_do_action failed -1. Output Control action 'deconfigure' returned an error. rc=2\nTransformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist\n", :data=>{:time=>nil, :output=>"Control action 'deconfigure' returned an error. rc=2\nTransformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist\n", :exitcode=>-1}}>] (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:10.241 [DEBUG] DEBUG: MCollective Response Time (execute_direct: deconfigure): 1.803742518s  (Request ID: c167c0f4f1c1b3b95a8c0a91a3fd8bfb) (pid:25429)
>2013-03-20 23:18:10.241 [DEBUG] DEBUG: server results: Control action 'deconfigure' returned an error. rc=2 (pid:25429)
>2013-03-20 23:18:10.245 [DEBUG] DEBUG: server results: Transformation failed: Source file /var/lib/openshift/62c63c7c91d511e2a43412313d0439e5/app-root/runtime/repo/.openshift/config/standalone.xml does not exist (pid:25429)
>2013-03-20 23:18:10.247 [DEBUG] DEBUG: rpc_exec: Filtering rpc_exec to servers ["ip-10-114-70-19"] (pid:25429)
>2013-03-20 23:18:10.249 [DEBUG] DEBUG: rpc_exec: rpc_client=#<MCollective::RPC::Client:0x00000004f0d3a0> (pid:25429)
>2013-03-20 23:18:10.384 [DEBUG] DEBUG: Application 'kit' not found on node 'ip-10-114-70-19'.  Continuing with deconfigure. (pid:25429)
>2013-03-20 23:18:10.384 [ERROR] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:25429)
>2013-03-20 23:18:10.385 [ERROR] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2533:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2681:in `run_cartridge_command'", "/var/www/openshift/broker/lib/online/broker/mcollective_ext.rb:13:in `run_cartridge_command'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2285:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:698:in `configure_cartridge'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/gear.rb:122:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:185:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:146:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:146:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:1047:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:360:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:1089:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:358:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/controllers/emb_cart_controller.rb:176:in `create'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:459:in `block in _run__489545799603073098__process_action__1025710007743042928__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_307'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/lib/openshift/controller/action_log.rb:34:in `set_logged_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_307'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__489545799603073098__process_action__1025710007743042928__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongo_mapper-0.11.1/lib/mongo_mapper/middleware/identity_map.rb:10:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/unit_of_work.rb:39:in `unit_of_work'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__3288767657039137238__call__980304224592271812__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:517:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:25429)
>2013-03-20 23:18:10.385 [ERROR] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:25429)
>2013-03-20 23:18:10.385 [ERROR] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:25429)
>2013-03-20 23:18:10.386 [DEBUG] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2533:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2681:in `run_cartridge_command'", "/var/www/openshift/broker/lib/online/broker/mcollective_ext.rb:13:in `run_cartridge_command'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:2285:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.6.3/lib/openshift/mcollective_application_container_proxy.rb:698:in `configure_cartridge'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/gear.rb:122:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:185:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:146:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/pending_app_op_group.rb:146:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:1047:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:360:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:1089:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/models/application.rb:358:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/app/controllers/emb_cart_controller.rb:176:in `create'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:459:in `block in _run__489545799603073098__process_action__1025710007743042928__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_307'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.6.3/lib/openshift/controller/action_log.rb:34:in `set_logged_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_307'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__489545799603073098__process_action__1025710007743042928__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongo_mapper-0.11.1/lib/mongo_mapper/middleware/identity_map.rb:10:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/unit_of_work.rb:39:in `unit_of_work'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__3288767657039137238__call__980304224592271812__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:517:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:25429)
>2013-03-20 23:18:10.395 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"514a7afbe491f5fca7000002"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.5359ms) (pid:25429)
>2013-03-20 23:18:10.412 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"514a7bede491f5fca700003a", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, {"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "state"=>:completed}, {"_id"=>"514a7bede491f5fca7000039", "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}}, "op_type"=>:new_component, "prereq"=>[nil], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"514a7bede491f5fca700003b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"514a7afce491f5fca7000010", "gear_id"=>"514a7afbe491f5fca7000002", "comp_spec"=>{"comp"=>"switchyard-0.6", "cart"=>"switchyard-0.6"}, "init_git_url"=>nil}, "prereq"=>["514a7bede491f5fca7000039", []]}, {"_id"=>"514a7bede491f5fca700003c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "prereq"=>["514a7bede491f5fca700003a", "514a7bede491f5fca7000039", "514a7bede491f5fca700003b"]}, {"_id"=>"514a7bede491f5fca700003d", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["514a7bede491f5fca700003c"]}]}} flags=[] (pid:25429)
>2013-03-20 23:18:10.416 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (6.4843ms) (pid:25429)
>2013-03-20 23:18:10.419 [DEBUG] Rollback set_group_overrides (pid:25429)
>2013-03-20 23:18:10.433 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}], "updated_at"=>2013-03-21 03:18:10 UTC}} flags=[] (pid:25429)
>2013-03-20 23:18:10.433 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (3.2730ms) (pid:25429)
>2013-03-20 23:18:10.435 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:rolledback}} flags=[] (pid:25429)
>2013-03-20 23:18:10.436 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7610ms) (pid:25429)
>2013-03-20 23:18:10.437 [DEBUG] Rollback new_component (pid:25429)
>2013-03-20 23:18:10.441 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$pull"=>{"component_instances"=>{"_id"=>"514a7bede491f5fca700003e"}}} flags=[] (pid:25429)
>2013-03-20 23:18:10.441 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4916ms) (pid:25429)
>2013-03-20 23:18:10.443 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:rolledback}} flags=[] (pid:25429)
>2013-03-20 23:18:10.443 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6065ms) (pid:25429)
>2013-03-20 23:18:10.444 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"514a7afbe491f5fca7000002"} update={"$pull"=>{"pending_op_groups"=>{"_id"=>"514a7bede491f5fca7000038"}}} flags=[] (pid:25429)
>2013-03-20 23:18:10.444 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4134ms) (pid:25429)
>2013-03-20 23:18:10.449 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514a7a9fe491f57f4e000001", "locked"=>false, "app_ids.514a7afbe491f5fca7000002"=>{"$exists"=>true}}, :new=>true, :update=>{"$unset"=>{"app_ids.514a7afbe491f5fca7000002"=>""}}} (3.2179ms) (pid:25429)
>2013-03-20 23:18:10.449 [INFO ] Completed 500 Internal Server Error in 5246ms (pid:25429)
>2013-03-20 23:18:10.452 [FATAL] OpenShift::NodeException (Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support.):
>  lib/online/broker/mcollective_ext.rb:13:in `run_cartridge_command' (pid:25429)
>2013-03-20 23:18:10.537 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_trace.erb (1.7ms) (pid:25429)
>2013-03-20 23:18:10.548 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (1.3ms) (pid:25429)
>2013-03-20 23:18:10.548 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (22.6ms) (pid:25429)
>2013-03-20 23:18:12.326 [INFO ] Started GET "/broker/rest/user/keys.json" for 127.0.0.1 at 2013-03-20 23:18:12 -0400 (pid:25429)
>2013-03-20 23:18:12.331 [INFO ] Started GET "/broker/rest/domains.json" for 127.0.0.1 at 2013-03-20 23:18:12 -0400 (pid:1832)
>2013-03-20 23:18:12.332 [INFO ] Processing by DomainsController#index as JSON (pid:1832)
>2013-03-20 23:18:12.333 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (0.5212ms) (pid:1832)
>2013-03-20 23:18:12.337 [INFO ] Processing by KeysController#index as JSON (pid:25429)
>2013-03-20 23:18:12.344 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"9d88f5e208c67f0608e8271f1b5a8864e293bd93087ecf22d0b7bd7b644f0049"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (9.3861ms) (pid:1832)
>2013-03-20 23:18:12.350 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"9d88f5e208c67f0608e8271f1b5a8864e293bd93087ecf22d0b7bd7b644f0049"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.8273ms) (pid:25429)
>2013-03-20 23:18:12.379 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7bd8e491f5fca7000035"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (33.7944ms) (pid:1832)
>2013-03-20 23:18:12.380 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa IP=127.0.0.1 SCOPES=session Authenticated (pid:1832)
>2013-03-20 23:18:12.382 [DEBUG] Dalli::Server#connect localhost:11212 (pid:25580)
>2013-03-20 23:18:12.385 [INFO ] localhost:11212 failed (count: 2) (pid:25580)
>2013-03-20 23:18:12.385 [DEBUG] localhost:11212 is still down (for 278.913 seconds now) (pid:25580)
>2013-03-20 23:18:12.385 [DEBUG] down_retry_delay not reached for localhost:11212 (1.000 seconds left) (pid:25580)
>2013-03-20 23:18:12.386 [INFO ] Started GET "/broker/rest/user/authorizations.json" for 127.0.0.1 at 2013-03-20 23:18:12 -0400 (pid:25580)
>2013-03-20 23:18:12.389 [DEBUG] Getting domains for user aaa (pid:1832)
>2013-03-20 23:18:12.390 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"514a7bd8e491f5fca7000035"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (0.6001ms) (pid:1832)
>2013-03-20 23:18:12.390 [DEBUG] SUCCESS ACTION=LIST_DOMAINS USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa (pid:1832)
>2013-03-20 23:18:12.391 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7bd8e491f5fca7000035"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (12.6984ms) (pid:25429)
>2013-03-20 23:18:12.395 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa IP=127.0.0.1 SCOPES=session Authenticated (pid:25429)
>2013-03-20 23:18:12.396 [INFO ] Processing by AuthorizationsController#index as JSON (pid:25580)
>2013-03-20 23:18:12.399 [INFO ] Completed 200 OK in 67ms (Views: 0.3ms) (pid:1832)
>2013-03-20 23:18:12.402 [DEBUG] SUCCESS ACTION=LIST_KEYS USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa Found 0 ssh keys (pid:25429)
>2013-03-20 23:18:12.404 [INFO ] Completed 200 OK in 66ms (Views: 0.4ms) (pid:25429)
>2013-03-20 23:18:12.405 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"9d88f5e208c67f0608e8271f1b5a8864e293bd93087ecf22d0b7bd7b644f0049"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.9127ms) (pid:25580)
>2013-03-20 23:18:12.411 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7bd8e491f5fca7000035"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (4.7154ms) (pid:25580)
>2013-03-20 23:18:12.412 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa IP=127.0.0.1 SCOPES=session Authenticated (pid:25580)
>2013-03-20 23:18:12.420 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"user_id"=>"514a7bd8e491f5fca7000035", "expires_at"=>{"$gt"=>2013-03-21 03:18:12 UTC}, "revoked_at"=>nil}, "$orderby"=>{"created_at"=>-1}} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (2.6221ms) (pid:25580)
>2013-03-20 23:18:12.423 [DEBUG] SUCCESS ACTION=LIST_AUTHORIZATIONS USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa IP=127.0.0.1 List authorizations (pid:25580)
>2013-03-20 23:18:12.470 [DEBUG] Dalli::Server#connect localhost:11212 (pid:25429)
>2013-03-20 23:18:12.475 [INFO ] localhost:11212 failed (count: 15) (pid:25429)
>2013-03-20 23:18:12.475 [DEBUG] localhost:11212 is still down (for 317.234 seconds now) (pid:25429)
>2013-03-20 23:18:12.477 [INFO ] Started GET "/broker/rest/user.json" for 127.0.0.1 at 2013-03-20 23:18:12 -0400 (pid:25429)
>2013-03-20 23:18:12.479 [INFO ] Processing by UserExtController#show as JSON (pid:25429)
>2013-03-20 23:18:12.481 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"9d88f5e208c67f0608e8271f1b5a8864e293bd93087ecf22d0b7bd7b644f0049"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.7172ms) (pid:25429)
>2013-03-20 23:18:12.486 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514a7bd8e491f5fca7000035"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.5417ms) (pid:25429)
>2013-03-20 23:18:12.488 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa IP=127.0.0.1 SCOPES=session Authenticated (pid:25429)
>2013-03-20 23:18:12.495 [DEBUG] SUCCESS ACTION=SHOW_USER USER_ID=514a7bd8e491f5fca7000035 LOGIN=aaa (pid:25429)
>2013-03-20 23:18:12.580 [INFO ] Completed 200 OK in 101ms (Views: 5.7ms) (pid:25429)
>2013-03-20 23:18:12.612 [INFO ] Completed 200 OK in 216ms (Views: 0.8ms) (pid:25580)
>2013-03-20 23:18:12.661 [DEBUG] down_retry_delay not reached for localhost:11212 (0.724 seconds left) (pid:25580)
>2013-03-20 23:18:12.662 [INFO ] Started GET "/broker/rest/plans/freeshift.json" for 127.0.0.1 at 2013-03-20 23:18:12 -0400 (pid:25580)
>2013-03-20 23:18:12.666 [INFO ] Processing by PlansController#show as JSON (pid:25580)
>2013-03-20 23:18:12.670 [INFO ] Parameters: {"id"=>"freeshift"} (pid:25580)
>2013-03-20 23:18:12.671 [DEBUG] SUCCESS ACTION=SHOW_PLAN USER_ID= LOGIN= (pid:25580)
>2013-03-20 23:18:12.674 [INFO ] Completed 200 OK in 4ms (Views: 0.7ms) (pid:25580)
>2013-03-20 23:18:13.693 [DEBUG] Dalli::Server#connect localhost:11212 (pid:25580)
>2013-03-20 23:18:13.697 [INFO ] localhost:11212 failed (count: 3) (pid:25580)
>2013-03-20 23:18:13.697 [DEBUG] localhost:11212 is still down (for 280.225 seconds now) (pid:25580)
>2013-03-20 23:18:13.698 [INFO ] Started GET "/broker/rest/environment.json" for 127.0.0.1 at 2013-03-20 23:18:13 -0400 (pid:25580)
>2013-03-20 23:18:13.701 [INFO ] Processing by EnvironmentController#show as JSON (pid:25580)
>2013-03-20 23:18:13.703 [DEBUG] SUCCESS ACTION=GET_ENVIRONMENT USER_ID= LOGIN= Showing broker environment (pid:25580)
>2013-03-20 23:18:13.708 [INFO ] Completed 200 OK in 6ms (Views: 2.5ms) (pid:25580)
>

Actions: View

Attachments on bug 921902: 710493 | 713581 | 713582