Attachment 687439 Details for Bug 904081 – broker log

broker log

development.log (text/x-log), 76.22 KB, created by jizhao on 2013-01-25 12:24:25 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: jizhao

Created: 2013-01-25 12:24:25 UTC

Size: 76.22 KB

patch

obsolete

>2013-01-25 07:06:25.467 [INFO ] Started GET "/broker/rest/api" for 209.132.181.86 at 2013-01-25 07:06:25 -0500 (pid:2556)
>2013-01-25 07:06:25.468 [INFO ] Processing by BaseController#show as JSON (pid:2556)
>2013-01-25 07:06:25.468 [DEBUG] application/json (pid:2556)
>2013-01-25 07:06:25.476 [INFO ] Completed 200 OK in 8ms (Views: 3.0ms) (pid:2556)
>2013-01-25 07:06:25.645 [INFO ] Started GET "/broker/rest/cartridges" for 209.132.181.86 at 2013-01-25 07:06:25 -0500 (pid:2556)
>2013-01-25 07:06:25.647 [INFO ] Processing by CartridgesController#index as JSON (pid:2556)
>2013-01-25 07:06:25.647 [DEBUG] application/json (pid:2556)
>2013-01-25 07:06:25.652 [DEBUG] [REQ_ID=] ACTION=LIST_CARTRIDGES List all cartridges (pid:2556)
>2013-01-25 07:06:25.662 [INFO ] Completed 200 OK in 15ms (Views: 8.3ms) (pid:2556)
>2013-01-25 07:06:26.464 [INFO ] Started GET "/broker/rest/domains" for 209.132.181.86 at 2013-01-25 07:06:26 -0500 (pid:2556)
>2013-01-25 07:06:26.465 [INFO ] Processing by DomainsController#index as JSON (pid:2556)
>2013-01-25 07:06:26.466 [DEBUG] [REQ_ID=b05a0baff47a462fb2ff2cad52729848] ACTION=AUTHENTICATE Access denied (pid:2556)
>2013-01-25 07:06:26.467 [INFO ] Filter chain halted as :authenticate rendered or redirected (pid:2556)
>2013-01-25 07:06:26.467 [INFO ] Completed 401 Unauthorized in 2ms (pid:2556)
>2013-01-25 07:06:26.622 [INFO ] Started GET "/broker/rest/domains" for 209.132.181.86 at 2013-01-25 07:06:26 -0500 (pid:2556)
>2013-01-25 07:06:26.624 [INFO ] Processing by DomainsController#index as JSON (pid:2556)
>2013-01-25 07:06:26.631 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"login"=>"jizhao+1@redhat.com"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (6.0508ms) (pid:2556)
>2013-01-25 07:06:26.632 [DEBUG] application/json (pid:2556)
>2013-01-25 07:06:26.633 [DEBUG] Getting domains for user jizhao+1@redhat.com (pid:2556)
>2013-01-25 07:06:26.634 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.7124ms) (pid:2556)
>2013-01-25 07:06:26.636 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"51027256032800fc09000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4239ms) (pid:2556)
>2013-01-25 07:06:26.637 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.5603ms) (pid:2556)
>2013-01-25 07:06:26.638 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.4129ms) (pid:2556)
>2013-01-25 07:06:26.641 [DEBUG] [REQ_ID=a1e653a929d34db3832a3198fd2d35c0] ACTION=LIST_DOMAINS (pid:2556)
>2013-01-25 07:06:26.645 [INFO ] Completed 200 OK in 21ms (Views: 3.1ms) (pid:2556)
>2013-01-25 07:06:27.268 [INFO ] Started POST "/broker/rest/domains/jizhao1/applications" for 209.132.181.86 at 2013-01-25 07:06:27 -0500 (pid:2556)
>2013-01-25 07:06:27.272 [INFO ] Processing by ApplicationsController#create as JSON (pid:2556)
>2013-01-25 07:06:27.272 [INFO ] Parameters: {"name"=>"app1", "scale"=>true, "cartridges"=>["jbossas-7"], "domain_id"=>"jizhao1", "application"=>{"name"=>"app1"}} (pid:2556)
>2013-01-25 07:06:27.274 [DEBUG] [REQ_ID=6ed81957b60543458ba7d70da406b51b] ACTION=AUTHENTICATE Access denied (pid:2556)
>2013-01-25 07:06:27.274 [INFO ] Filter chain halted as :authenticate rendered or redirected (pid:2556)
>2013-01-25 07:06:27.274 [INFO ] Completed 401 Unauthorized in 2ms (pid:2556)
>2013-01-25 07:06:27.417 [INFO ] Started POST "/broker/rest/domains/jizhao1/applications" for 209.132.181.86 at 2013-01-25 07:06:27 -0500 (pid:2556)
>2013-01-25 07:06:27.419 [INFO ] Processing by ApplicationsController#create as JSON (pid:2556)
>2013-01-25 07:06:27.419 [INFO ] Parameters: {"name"=>"app1", "scale"=>true, "cartridges"=>["jbossas-7"], "domain_id"=>"jizhao1", "application"=>{"name"=>"app1"}} (pid:2556)
>2013-01-25 07:06:27.421 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"login"=>"jizhao+1@redhat.com"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.6728ms) (pid:2556)
>2013-01-25 07:06:27.421 [DEBUG] application/json (pid:2556)
>2013-01-25 07:06:27.422 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"owner_id"=>"51027256032800fc09000001", "canonical_namespace"=>"jizhao1"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.5498ms) (pid:2556)
>2013-01-25 07:06:27.423 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"51027256032800fc09000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.3364ms) (pid:2556)
>2013-01-25 07:06:27.424 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3312ms) (pid:2556)
>2013-01-25 07:06:27.425 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.4058ms) (pid:2556)
>2013-01-25 07:06:27.426 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:count=>"applications", :query=>{"domain_id"=>"51027256032800fc09000003", "canonical_name"=>"app1"}} (0.4253ms) (pid:2556)
>2013-01-25 07:06:27.426 [DEBUG] Checking to see if user limit for number of apps has been reached (pid:2556)
>2013-01-25 07:06:27.432 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=applications documents=[{"_id"=>"51027543032800fc090000a3", "uuid"=>"51027543032800fc090000a3", "domain_requires"=>[], "group_overrides"=>[], "user_ids"=>[], "aliases"=>[], "component_start_order"=>[], "component_stop_order"=>[], "component_configure_order"=>[], "default_gear_size"=>"small", "init_git_url"=>nil, "name"=>"app1", "canonical_name"=>"app1", "scalable"=>true, "domain_id"=>"51027256032800fc09000003", "updated_at"=>2013-01-25 12:06:27 UTC, "created_at"=>2013-01-25 12:06:27 UTC}] flags=[] (0.5968ms) (pid:2556)
>2013-01-25 07:06:27.438 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "app_ids"=>{"$nin"=>["51027543032800fc090000a3"]}}, :new=>true, :update=>{"$push"=>{:app_ids=>"51027543032800fc090000a3"}}} (0.7639ms) (pid:2556)
>2013-01-25 07:06:27.444 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$push"=>{"pending_op_groups"=>{"_id"=>"51027543032800fc090000a4", "num_gears_added"=>0, "num_gears_removed"=>0, "num_gears_created"=>0, "num_gears_destroyed"=>0, "num_gears_rolled_back"=>0, "user_agent"=>"rhc/1.3.8 (ruby 1.8.7; x86_64-linux) (2.3.2, ruby 1.8.7 (2011-06-30) [x86_64-linux])", "op_type"=>:add_features, "args"=>{"features"=>["jbossas-7", "web_proxy"], "group_overrides"=>[], "init_git_url"=>nil}, "parent_op_id"=>nil, "updated_at"=>2013-01-25 12:06:27 UTC, "created_at"=>2013-01-25 12:06:27 UTC}}} flags=[] (0.4523ms) (pid:2556)
>2013-01-25 07:06:27.445 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.6013ms) (pid:2556)
>2013-01-25 07:06:27.457 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"51027256032800fc09000003"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4511ms) (pid:2556)
>2013-01-25 07:06:27.459 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"51027256032800fc09000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.3772ms) (pid:2556)
>2013-01-25 07:06:27.460 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.4709ms) (pid:2556)
>2013-01-25 07:06:27.461 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3240ms) (pid:2556)
>2013-01-25 07:06:27.462 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3228ms) (pid:2556)
>2013-01-25 07:06:27.469 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3700ms) (pid:2556)
>2013-01-25 07:06:27.503 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"51027256032800fc09000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.5198ms) (pid:2556)
>2013-01-25 07:06:27.504 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x00000006f243c8>"=>1359115587}], "app_ids"=>"51027543032800fc090000a3"}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1359116187}}} (0.6855ms) (pid:2556)
>2013-01-25 07:06:27.505 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"51027256032800fc09000001"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4022ms) (pid:2556)
>2013-01-25 07:06:27.589 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4"} update={"$pushAll"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51027543032800fc090000a5", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[]}}, {"_id"=>"51027543032800fc090000a7", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_group_instance, "args"=>{"group_instance_id"=>"51027543032800fc090000bf"}}, {"_id"=>"51027543032800fc090000aa", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000a9"], "retry_rollback_op"=>"51027543032800fc090000a9"}, {"_id"=>"51027543032800fc090000a8", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:init_gear, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3", "host_singletons"=>true, "app_dns"=>true}, "prereq"=>["51027543032800fc090000a7"]}, {"_id"=>"51027543032800fc090000b6", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"login"=>"jizhao+1@redhat.com", "gear_ref"=>"51027543032800fc090000a3", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51027543032800fc090000a8"]}, {"_id"=>"51027543032800fc090000a9", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000a8"]}, {"_id"=>"51027543032800fc090000ab", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000aa"]}, {"_id"=>"51027543032800fc090000b7", "state"=>:init, "retry_count"=>0, "saved_values"=>{"additional_filesystem_gb"=>0}, "op_type"=>:set_gear_additional_filesystem_gb, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3", "additional_filesystem_gb"=>0}, "prereq"=>["51027543032800fc090000a8"]}, {"_id"=>"51027543032800fc090000b8", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[{"_id"=>"51027263032800fc09000005", "content"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQC5uPEUQDTBRE2sbOSEdcUJ+1gO0MhEYFHpmNocWK23hNMhffLWHRCiJgZDDe7Xg6VHwDVL2UY5mW2AR8QIdvKY/HiIiB4VACUECwiEZZ0JxlMoeWCL56u8O43a5Ti8d0JhElOjqoPyJXjGgnb5icw8Hm/IhaHLzBKy+XXjysDEyiI1NGoDdpH6KwrxtQtxJOvv5iuoSQnv6wRoNuPkllZik0XRLCiaeAfu5EsbvPsYPgSF4DWiglQILQk1aQSqHxFY2HEiCtF/8FU4/j8inMA9skuGholshemlkV+hqOEFbcztdsw05FicLctW4oPC51DdYTYUgScdCEPP3cwKO9ez", "name"=>"51027256032800fc09000001-default", "type"=>"ssh-rsa"}, {"_id"=>"51027263032800fc09000005", "content"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQC5uPEUQDTBRE2sbOSEdcUJ+1gO0MhEYFHpmNocWK23hNMhffLWHRCiJgZDDe7Xg6VHwDVL2UY5mW2AR8QIdvKY/HiIiB4VACUECwiEZZ0JxlMoeWCL56u8O43a5Ti8d0JhElOjqoPyJXjGgnb5icw8Hm/IhaHLzBKy+XXjysDEyiI1NGoDdpH6KwrxtQtxJOvv5iuoSQnv6wRoNuPkllZik0XRLCiaeAfu5EsbvPsYPgSF4DWiglQILQk1aQSqHxFY2HEiCtF/8FU4/j8inMA9skuGholshemlkV+hqOEFbcztdsw05FicLctW4oPC51DdYTYUgScdCEPP3cwKO9ez", "name"=>"51027256032800fc09000001-default", "type"=>"ssh-rsa"}], "add_env_vars"=>[], "group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000ab"]}, {"_id"=>"51027543032800fc090000ac", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "comp_spec"=>{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}}, "prereq"=>["51027543032800fc090000a7"]}, {"_id"=>"51027543032800fc090000ad", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3", "comp_spec"=>{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}, "init_git_url"=>nil}, "prereq"=>["51027543032800fc090000ac", "51027543032800fc090000ab"]}, {"_id"=>"51027543032800fc090000b9", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:expose_port, "args"=>{"group_instance_id"=>"51027543032800fc090000bf", "gear_id"=>"51027543032800fc090000a3", "comp_spec"=>{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}}, "prereq"=>["51027543032800fc090000ad", "51027543032800fc090000ab"]}, {"_id"=>"51027543032800fc090000af", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_group_instance, "args"=>{"group_instance_id"=>"51027543032800fc090000c0"}}, {"_id"=>"51027543032800fc090000b2", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000b1"], "retry_rollback_op"=>"51027543032800fc090000b1"}, {"_id"=>"51027543032800fc090000b0", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:init_gear, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3", "host_singletons"=>true, "app_dns"=>true}, "prereq"=>["51027543032800fc090000af"]}, {"_id"=>"51027543032800fc090000ba", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"login"=>"jizhao+1@redhat.com", "gear_ref"=>"51027543032800fc090000a3", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51027543032800fc090000b0"]}, {"_id"=>"51027543032800fc090000b1", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000b0"]}, {"_id"=>"51027543032800fc090000b3", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000b2"]}, {"_id"=>"51027543032800fc090000bb", "state"=>:init, "retry_count"=>0, "saved_values"=>{"additional_filesystem_gb"=>0}, "op_type"=>:set_gear_additional_filesystem_gb, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3", "additional_filesystem_gb"=>0}, "prereq"=>["51027543032800fc090000b0"]}, {"_id"=>"51027543032800fc090000bc", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[{"_id"=>"51027263032800fc09000005", "content"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQC5uPEUQDTBRE2sbOSEdcUJ+1gO0MhEYFHpmNocWK23hNMhffLWHRCiJgZDDe7Xg6VHwDVL2UY5mW2AR8QIdvKY/HiIiB4VACUECwiEZZ0JxlMoeWCL56u8O43a5Ti8d0JhElOjqoPyJXjGgnb5icw8Hm/IhaHLzBKy+XXjysDEyiI1NGoDdpH6KwrxtQtxJOvv5iuoSQnv6wRoNuPkllZik0XRLCiaeAfu5EsbvPsYPgSF4DWiglQILQk1aQSqHxFY2HEiCtF/8FU4/j8inMA9skuGholshemlkV+hqOEFbcztdsw05FicLctW4oPC51DdYTYUgScdCEPP3cwKO9ez", "name"=>"51027256032800fc09000001-default", "type"=>"ssh-rsa"}, {"_id"=>"51027263032800fc09000005", "content"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQC5uPEUQDTBRE2sbOSEdcUJ+1gO0MhEYFHpmNocWK23hNMhffLWHRCiJgZDDe7Xg6VHwDVL2UY5mW2AR8QIdvKY/HiIiB4VACUECwiEZZ0JxlMoeWCL56u8O43a5Ti8d0JhElOjqoPyJXjGgnb5icw8Hm/IhaHLzBKy+XXjysDEyiI1NGoDdpH6KwrxtQtxJOvv5iuoSQnv6wRoNuPkllZik0XRLCiaeAfu5EsbvPsYPgSF4DWiglQILQk1aQSqHxFY2HEiCtF/8FU4/j8inMA9skuGholshemlkV+hqOEFbcztdsw05FicLctW4oPC51DdYTYUgScdCEPP3cwKO9ez", "name"=>"51027256032800fc09000001-default", "type"=>"ssh-rsa"}], "add_env_vars"=>[], "group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3"}, "prereq"=>["51027543032800fc090000b3"]}, {"_id"=>"51027543032800fc090000b4", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "comp_spec"=>{"comp"=>"web_proxy", "cart"=>"haproxy-1.4"}}, "prereq"=>["51027543032800fc090000af", "51027543032800fc090000ad"]}, {"_id"=>"51027543032800fc090000b5", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3", "comp_spec"=>{"comp"=>"web_proxy", "cart"=>"haproxy-1.4"}, "init_git_url"=>nil}, "prereq"=>["51027543032800fc090000b4", "51027543032800fc090000b3", "51027543032800fc090000ad"]}, {"_id"=>"51027543032800fc090000bd", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:expose_port, "args"=>{"group_instance_id"=>"51027543032800fc090000c0", "gear_id"=>"51027543032800fc090000a3", "comp_spec"=>{"comp"=>"web_proxy", "cart"=>"haproxy-1.4"}}, "prereq"=>["51027543032800fc090000b5", "51027543032800fc090000b3"]}, {"_id"=>"51027543032800fc090000be", "state"=>:init, "retry_count"=>0, "saved_values"=>{:connections=>[]}, "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"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"haproxy-1.4", "comp"=>"web_proxy"}, "from_connector_name"=>"publish-http-url", "to_connector_name"=>"set-proxy", "connection_type"=>"NET_TCP:httpd-proxy-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"haproxy-1.4", "comp"=>"web_proxy"}, "from_connector_name"=>"publish-gear-endpoint", "to_connector_name"=>"set-gear-endpoints", "connection_type"=>"NET_TCP:gear-endpoint-info"}]}, "prereq"=>["51027543032800fc090000a5", "51027543032800fc090000a7", "51027543032800fc090000aa", "51027543032800fc090000a8", "51027543032800fc090000b6", "51027543032800fc090000a9", "51027543032800fc090000ab", "51027543032800fc090000b7", "51027543032800fc090000b8", "51027543032800fc090000ac", "51027543032800fc090000ad", "51027543032800fc090000b9", "51027543032800fc090000af", "51027543032800fc090000b2", "51027543032800fc090000b0", "51027543032800fc090000ba", "51027543032800fc090000b1", "51027543032800fc090000b3", "51027543032800fc090000bb", "51027543032800fc090000bc", "51027543032800fc090000b4", "51027543032800fc090000b5", "51027543032800fc090000bd"]}, {"_id"=>"51027543032800fc090000c1", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51027543032800fc090000be"]}]}} flags=[] (2.6424ms) (pid:2556)
>2013-01-25 07:06:27.606 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4"} update={"$set"=>{"pending_op_groups.0.num_gears_added"=>2, "pending_op_groups.0.updated_at"=>2013-01-25 12:06:27 UTC}} flags=[] (0.2844ms) (pid:2556)
>2013-01-25 07:06:27.634 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.5734ms) (pid:2556)
>2013-01-25 07:06:27.635 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3362ms) (pid:2556)
>2013-01-25 07:06:27.638 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=cloud_users selector={"_id"=>"51027256032800fc09000001"} update={"$set"=>{"consumed_gears"=>2, "updated_at"=>2013-01-25 12:06:27 UTC}} flags=[] (0.2992ms) (pid:2556)
>2013-01-25 07:06:27.639 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "locked"=>true, "app_ids"=>"51027543032800fc090000a3"}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.6123ms) (pid:2556)
>2013-01-25 07:06:27.642 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.7385ms) (pid:2556)
>2013-01-25 07:06:27.656 [DEBUG] Execute set_group_overrides (pid:2556)
>2013-01-25 07:06:27.660 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a5"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:completed}} flags=[] (0.6700ms) (pid:2556)
>2013-01-25 07:06:27.660 [DEBUG] Execute create_group_instance (pid:2556)
>2013-01-25 07:06:27.662 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$push"=>{"group_instances"=>{"_id"=>"51027543032800fc090000bf"}}} flags=[] (0.3572ms) (pid:2556)
>2013-01-25 07:06:27.663 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a7"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:completed}} flags=[] (0.4342ms) (pid:2556)
>2013-01-25 07:06:27.663 [DEBUG] Execute create_group_instance (pid:2556)
>2013-01-25 07:06:27.664 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$push"=>{"group_instances"=>{"_id"=>"51027543032800fc090000c0"}}} flags=[] (0.3116ms) (pid:2556)
>2013-01-25 07:06:27.665 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000af"} update={"$set"=>{"pending_op_groups.0.pending_ops.12.state"=>:completed}} flags=[] (0.4961ms) (pid:2556)
>2013-01-25 07:06:27.667 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.7695ms) (pid:2556)
>2013-01-25 07:06:27.682 [DEBUG] Execute init_gear (pid:2556)
>2013-01-25 07:06:27.684 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf"} update={"$push"=>{"group_instances.0.gears"=>{"_id"=>"51027543032800fc090000a3", "uuid"=>"51027543032800fc090000a3", "host_singletons"=>true, "app_dns"=>true, "name"=>"app1"}}} flags=[] (0.7932ms) (pid:2556)
>2013-01-25 07:06:27.688 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a8"} update={"$set"=>{"pending_op_groups.0.pending_ops.3.state"=>:completed}} flags=[] (0.4430ms) (pid:2556)
>2013-01-25 07:06:27.689 [DEBUG] Execute new_component (pid:2556)
>2013-01-25 07:06:27.690 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$push"=>{"component_instances"=>{"_id"=>"51027543032800fc090000c5", "component_properties"=>{}, "cartridge_name"=>"jbossas-7", "component_name"=>"jbossas-7", "group_instance_id"=>"51027543032800fc090000bf"}}} flags=[] (0.3302ms) (pid:2556)
>2013-01-25 07:06:27.691 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000ac"} update={"$set"=>{"pending_op_groups.0.pending_ops.9.state"=>:completed}} flags=[] (0.4110ms) (pid:2556)
>2013-01-25 07:06:27.692 [DEBUG] Execute init_gear (pid:2556)
>2013-01-25 07:06:27.693 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0"} update={"$push"=>{"group_instances.1.gears"=>{"_id"=>"51027543032800fc090000a3", "uuid"=>"51027543032800fc090000a3", "host_singletons"=>true, "app_dns"=>true, "name"=>"app1"}}} flags=[] (0.3898ms) (pid:2556)
>2013-01-25 07:06:27.697 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b0"} update={"$set"=>{"pending_op_groups.0.pending_ops.14.state"=>:completed}} flags=[] (0.4308ms) (pid:2556)
>2013-01-25 07:06:27.699 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.8065ms) (pid:2556)
>2013-01-25 07:06:27.711 [DEBUG] Execute track_usage (pid:2556)
>2013-01-25 07:06:27.714 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage_records documents=[{"_id"=>"51027543032800fc090000c7", "event"=>"begin", "time"=>2013-01-25 12:06:27 UTC, "gear_id"=>"51027543032800fc090000a3", "usage_type"=>"GEAR_USAGE", "login"=>"jizhao+1@redhat.com", "gear_size"=>"small", "updated_at"=>2013-01-25 12:06:27 UTC, "created_at"=>2013-01-25 12:06:27 UTC}] flags=[] (0.5603ms) (pid:2556)
>2013-01-25 07:06:27.715 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage documents=[{"_id"=>"51027543032800fc090000c8", "login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "begin_time"=>2013-01-25 12:06:27 UTC, "usage_type"=>"GEAR_USAGE", "gear_size"=>"small", "updated_at"=>2013-01-25 12:06:27 UTC, "created_at"=>2013-01-25 12:06:27 UTC}] flags=[] (0.3722ms) (pid:2556)
>2013-01-25 07:06:27.717 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b6"} update={"$set"=>{"pending_op_groups.0.pending_ops.4.state"=>:completed}} flags=[] (0.5066ms) (pid:2556)
>2013-01-25 07:06:27.717 [DEBUG] Execute reserve_uid (pid:2556)
>2013-01-25 07:06:27.719 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=districts selector={"$query"=>{"available_capacity"=>{"$gte"=>0}, "gear_size"=>"small", "active_server_identities_size"=>{"$gte"=>0}}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4027ms) (pid:2556)
>2013-01-25 07:06:27.719 [DEBUG] DEBUG: rpc_get_fact: fact=active_capacity (pid:2556)
>2013-01-25 07:06:27.720 [DEBUG] DEBUG: rpc_exec: rpc_client=#<MCollective::RPC::Client:0x00000003cd5de0> (pid:2556)
>2013-01-25 07:06:29.780 [DEBUG] Current server: ip-10-99-46-100 active capacity: 0.0 (pid:2556)
>2013-01-25 07:06:29.780 [DEBUG] DEBUG: find_available_impl: current_server: ip-10-99-46-100: 0.0 (pid:2556)
>2013-01-25 07:06:29.782 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf", "group_instances.0.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.0.gears.0.server_identity"=>"ip-10-99-46-100"}} flags=[] (0.7875ms) (pid:2556)
>2013-01-25 07:06:29.852 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf", "group_instances.0.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.0.gears.0.uid"=>nil}} flags=[] (0.6404ms) (pid:2556)
>2013-01-25 07:06:29.854 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a9"} update={"$set"=>{"pending_op_groups.0.pending_ops.5.state"=>:completed}} flags=[] (1.0576ms) (pid:2556)
>2013-01-25 07:06:29.856 [DEBUG] Execute set_gear_additional_filesystem_gb (pid:2556)
>2013-01-25 07:06:29.856 [DEBUG] Execute track_usage (pid:2556)
>2013-01-25 07:06:29.860 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage_records documents=[{"_id"=>"51027545032800fc090000c9", "event"=>"begin", "time"=>2013-01-25 12:06:29 UTC, "gear_id"=>"51027543032800fc090000a3", "usage_type"=>"GEAR_USAGE", "login"=>"jizhao+1@redhat.com", "gear_size"=>"small", "updated_at"=>2013-01-25 12:06:29 UTC, "created_at"=>2013-01-25 12:06:29 UTC}] flags=[] (1.5643ms) (pid:2556)
>2013-01-25 07:06:29.862 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage documents=[{"_id"=>"51027545032800fc090000ca", "login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "begin_time"=>2013-01-25 12:06:29 UTC, "usage_type"=>"GEAR_USAGE", "gear_size"=>"small", "updated_at"=>2013-01-25 12:06:29 UTC, "created_at"=>2013-01-25 12:06:29 UTC}] flags=[] (0.4127ms) (pid:2556)
>2013-01-25 07:06:29.863 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000ba"} update={"$set"=>{"pending_op_groups.0.pending_ops.15.state"=>:completed}} flags=[] (0.7107ms) (pid:2556)
>2013-01-25 07:06:29.864 [DEBUG] Execute reserve_uid (pid:2556)
>2013-01-25 07:06:29.865 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=districts selector={"$query"=>{"available_capacity"=>{"$gte"=>0}, "gear_size"=>"small", "active_server_identities_size"=>{"$gte"=>0}}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4327ms) (pid:2556)
>2013-01-25 07:06:29.865 [DEBUG] DEBUG: rpc_get_fact: fact=active_capacity (pid:2556)
>2013-01-25 07:06:29.866 [DEBUG] DEBUG: rpc_exec: rpc_client=#<MCollective::RPC::Client:0x000000070e1378> (pid:2556)
>2013-01-25 07:06:31.980 [DEBUG] Current server: ip-10-99-46-100 active capacity: 0.0 (pid:2556)
>2013-01-25 07:06:31.980 [DEBUG] DEBUG: find_available_impl: current_server: ip-10-99-46-100: 0.0 (pid:2556)
>2013-01-25 07:06:31.983 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0", "group_instances.1.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.1.gears.0.server_identity"=>"ip-10-99-46-100"}} flags=[] (1.0352ms) (pid:2556)
>2013-01-25 07:06:32.561 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0", "group_instances.1.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.1.gears.0.uid"=>nil}} flags=[] (1.0803ms) (pid:2556)
>2013-01-25 07:06:32.578 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b1"} update={"$set"=>{"pending_op_groups.0.pending_ops.16.state"=>:completed}} flags=[] (0.7944ms) (pid:2556)
>2013-01-25 07:06:32.589 [DEBUG] Execute set_gear_additional_filesystem_gb (pid:2556)
>2013-01-25 07:06:32.616 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b7"} update={"$set"=>{"pending_op_groups.0.pending_ops.7.state"=>:completed}} flags=[] (1.2441ms) (pid:2556)
>2013-01-25 07:06:32.627 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000bb"} update={"$set"=>{"pending_op_groups.0.pending_ops.18.state"=>:completed}} flags=[] (0.6053ms) (pid:2556)
>2013-01-25 07:06:32.703 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (2.7888ms) (pid:2556)
>2013-01-25 07:06:32.804 [DEBUG] Execute create_gear (pid:2556)
>2013-01-25 07:06:32.823 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000005b35ee8> (pid:2556)
>2013-01-25 07:06:32.825 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-create", :args=>{"--with-app-uuid"=>"51027543032800fc090000a3", "--with-app-name"=>"app1", "--with-container-uuid"=>"51027543032800fc090000a3", "--with-container-name"=>"app1", "--with-namespace"=>"jizhao1"}}, ip-10-99-46-100, {'identity' => ip-10-99-46-100}) (pid:2556)
>2013-01-25 07:06:33.768 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000068f9b10 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-99-46-100", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (pid:2556)
>2013-01-25 07:06:33.772 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4"} update={"$inc"=>{"pending_op_groups.0.num_gears_created"=>1}} flags=[] (0.7622ms) (pid:2556)
>2013-01-25 07:06:33.773 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000aa"} update={"$set"=>{"pending_op_groups.0.pending_ops.2.state"=>:completed}} flags=[] (0.7293ms) (pid:2556)
>2013-01-25 07:06:33.775 [DEBUG] Execute create_gear (pid:2556)
>2013-01-25 07:06:33.778 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006660cc8> (pid:2556)
>2013-01-25 07:06:33.778 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-create", :args=>{"--with-app-uuid"=>"51027543032800fc090000a3", "--with-app-name"=>"app1", "--with-container-uuid"=>"51027543032800fc090000a3", "--with-container-name"=>"app1", "--with-namespace"=>"jizhao1"}}, ip-10-99-46-100, {'identity' => ip-10-99-46-100}) (pid:2556)
>2013-01-25 07:06:33.939 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000066e93e8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-99-46-100", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 129. Output ERROR: unable to create user account(9): useradd -u 501 -d /var/lib/openshift/51027543032800fc090000a3/ -s /usr/bin/oo-trap-user -c 'OpenShift guest' -m -k /etc/openshift/skel 51027543032800fc090000a3 stdout: useradd: user '51027543032800fc090000a3' already exists\n stderr: useradd: user '51027543032800fc090000a3' already exists\n", :data=>{:time=>nil, :output=>"ERROR: unable to create user account(9): useradd -u 501 -d /var/lib/openshift/51027543032800fc090000a3/ -s /usr/bin/oo-trap-user -c 'OpenShift guest' -m -k /etc/openshift/skel 51027543032800fc090000a3 stdout: useradd: user '51027543032800fc090000a3' already exists\n stderr: useradd: user '51027543032800fc090000a3' already exists\n", :exitcode=>129}}>] (pid:2556)
>2013-01-25 07:06:33.940 [DEBUG] DEBUG: server results: ERROR: unable to create user account(9): useradd -u 501 -d /var/lib/openshift/51027543032800fc090000a3/ -s /usr/bin/oo-trap-user -c 'OpenShift guest' -m -k /etc/openshift/skel 51027543032800fc090000a3 stdout: useradd: user '51027543032800fc090000a3' already exists (pid:2556)
>2013-01-25 07:06:33.941 [DEBUG] DEBUG: server results:  stderr: useradd: user '51027543032800fc090000a3' already exists (pid:2556)
>2013-01-25 07:06:33.941 [ERROR] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:2556)
>2013-01-25 07:06:33.942 [ERROR] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:2539:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:412:in `block in create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:401:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:401:in `create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/gear.rb:79:in `create_gear'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:170:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:127:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:127:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:957:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:336:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:999:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:334:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:96:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/controllers/applications_controller.rb:97: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:458:in `_run__1540345791705353483__process_action__4332582209622098459__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.5/lib/rack/mongoid/middleware/identity_map.rb:33:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.5/lib/mongoid/unit_of_work.rb:39:in `unit_of_work'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.5/lib/rack/mongoid/middleware/identity_map.rb:33: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__4156649091440266678__call__195784054749406948__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/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62: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:2556)
>2013-01-25 07:06:33.942 [ERROR] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:2556)
>2013-01-25 07:06:33.944 [DEBUG] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:2539:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:412:in `block in create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:401:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.4.1/lib/openshift/mcollective_application_container_proxy.rb:401:in `create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/gear.rb:79:in `create_gear'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:170:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:127:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/pending_app_op_group.rb:127:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:957:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:336:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:999:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:334:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/models/application.rb:96:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.4.1/app/controllers/applications_controller.rb:97: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:458:in `_run__1540345791705353483__process_action__4332582209622098459__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.5/lib/rack/mongoid/middleware/identity_map.rb:33:in `block in call'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.5/lib/mongoid/unit_of_work.rb:39:in `unit_of_work'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.5/lib/rack/mongoid/middleware/identity_map.rb:33: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__4156649091440266678__call__195784054749406948__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/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62: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:2556)
>2013-01-25 07:06:33.947 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (2.6104ms) (pid:2556)
>2013-01-25 07:06:33.955 [DEBUG] Rollback set_group_overrides (pid:2556)
>2013-01-25 07:06:33.959 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a5"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:rolledback}} flags=[] (0.6340ms) (pid:2556)
>2013-01-25 07:06:33.959 [DEBUG] Rollback create_gear (pid:2556)
>2013-01-25 07:06:33.963 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006a67f10> (pid:2556)
>2013-01-25 07:06:33.963 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"51027543032800fc090000a3", "--with-app-name"=>"app1", "--with-container-uuid"=>"51027543032800fc090000a3", "--with-container-name"=>"app1", "--with-namespace"=>"jizhao1"}}, ip-10-99-46-100, {'identity' => ip-10-99-46-100}) (pid:2556)
>2013-01-25 07:06:36.771 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x0000000699e638 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-99-46-100", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (pid:2556)
>2013-01-25 07:06:36.848 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4"} update={"$inc"=>{"pending_op_groups.0.num_gears_rolled_back"=>1}} flags=[] (0.6912ms) (pid:2556)
>2013-01-25 07:06:36.893 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000aa"} update={"$set"=>{"pending_op_groups.0.pending_ops.2.state"=>:rolledback}} flags=[] (4.0059ms) (pid:2556)
>2013-01-25 07:06:36.895 [DEBUG] Rollback track_usage (pid:2556)
>2013-01-25 07:06:36.911 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage_records selector={"$query"=>{"login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "event"=>"begin", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.6459ms) (pid:2556)
>2013-01-25 07:06:36.927 [DEBUG] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage_records selector={"_id"=>"51027543032800fc090000c7"} flags=[:remove_first] (0.3049ms) (pid:2556)
>2013-01-25 07:06:36.940 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage selector={"$query"=>{"login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{"begin_time"=>-1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.5143ms) (pid:2556)
>2013-01-25 07:06:36.949 [DEBUG] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage selector={"_id"=>"51027545032800fc090000ca"} flags=[:remove_first] (0.3211ms) (pid:2556)
>2013-01-25 07:06:36.974 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b6"} update={"$set"=>{"pending_op_groups.0.pending_ops.4.state"=>:rolledback}} flags=[] (1.0846ms) (pid:2556)
>2013-01-25 07:06:36.976 [DEBUG] Rollback set_gear_additional_filesystem_gb (pid:2556)
>2013-01-25 07:06:36.987 [DEBUG] Rollback new_component (pid:2556)
>2013-01-25 07:06:36.100 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$pull"=>{"component_instances"=>{"_id"=>"51027543032800fc090000c5"}}} flags=[] (0.2666ms) (pid:2556)
>2013-01-25 07:06:36.101 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000ac"} update={"$set"=>{"pending_op_groups.0.pending_ops.9.state"=>:rolledback}} flags=[] (0.4179ms) (pid:2556)
>2013-01-25 07:06:36.101 [DEBUG] Rollback track_usage (pid:2556)
>2013-01-25 07:06:36.102 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage_records selector={"$query"=>{"login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "event"=>"begin", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.7477ms) (pid:2556)
>2013-01-25 07:06:36.103 [DEBUG] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage_records selector={"_id"=>"51027545032800fc090000c9"} flags=[:remove_first] (0.2222ms) (pid:2556)
>2013-01-25 07:06:36.104 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage selector={"$query"=>{"login"=>"jizhao+1@redhat.com", "gear_id"=>"51027543032800fc090000a3", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{"begin_time"=>-1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4091ms) (pid:2556)
>2013-01-25 07:06:36.104 [DEBUG] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage selector={"_id"=>"51027543032800fc090000c8"} flags=[:remove_first] (0.1998ms) (pid:2556)
>2013-01-25 07:06:36.105 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000ba"} update={"$set"=>{"pending_op_groups.0.pending_ops.15.state"=>:rolledback}} flags=[] (0.4411ms) (pid:2556)
>2013-01-25 07:06:36.105 [DEBUG] Rollback reserve_uid (pid:2556)
>2013-01-25 07:06:36.179 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0", "group_instances.1.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.1.gears.0.server_identity"=>nil}} flags=[] (0.5848ms) (pid:2556)
>2013-01-25 07:06:36.181 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0", "group_instances.1.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.1.gears.0.uid"=>nil}} flags=[] (1.2887ms) (pid:2556)
>2013-01-25 07:06:36.182 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b1"} update={"$set"=>{"pending_op_groups.0.pending_ops.16.state"=>:rolledback}} flags=[] (0.4194ms) (pid:2556)
>2013-01-25 07:06:36.182 [DEBUG] Rollback set_gear_additional_filesystem_gb (pid:2556)
>2013-01-25 07:06:36.189 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$set"=>{"updated_at"=>2013-01-25 12:06:36 UTC, "pending_op_groups.0.pending_ops.7.state"=>:rolledback, "pending_op_groups.0.pending_ops.18.state"=>:rolledback}} flags=[] (0.5820ms) (pid:2556)
>2013-01-25 07:06:36.192 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.6904ms) (pid:2556)
>2013-01-25 07:06:36.196 [DEBUG] Rollback reserve_uid (pid:2556)
>2013-01-25 07:06:36.375 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf", "group_instances.0.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.0.gears.0.server_identity"=>nil}} flags=[] (1.5225ms) (pid:2556)
>2013-01-25 07:06:36.377 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf", "group_instances.0.gears._id"=>"51027543032800fc090000a3"} update={"$set"=>{"group_instances.0.gears.0.uid"=>nil}} flags=[] (0.3393ms) (pid:2556)
>2013-01-25 07:06:36.378 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a9"} update={"$set"=>{"pending_op_groups.0.pending_ops.5.state"=>:rolledback}} flags=[] (0.4547ms) (pid:2556)
>2013-01-25 07:06:36.378 [DEBUG] Rollback init_gear (pid:2556)
>2013-01-25 07:06:36.381 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000c0"} update={"$pull"=>{"group_instances.1.gears"=>{"_id"=>"51027543032800fc090000a3"}}} flags=[] (0.4563ms) (pid:2556)
>2013-01-25 07:06:36.386 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000b0"} update={"$set"=>{"pending_op_groups.0.pending_ops.14.state"=>:rolledback}} flags=[] (0.5419ms) (pid:2556)
>2013-01-25 07:06:36.389 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.8945ms) (pid:2556)
>2013-01-25 07:06:36.393 [DEBUG] Rollback init_gear (pid:2556)
>2013-01-25 07:06:36.394 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "group_instances._id"=>"51027543032800fc090000bf"} update={"$pull"=>{"group_instances.0.gears"=>{"_id"=>"51027543032800fc090000a3"}}} flags=[] (0.5445ms) (pid:2556)
>2013-01-25 07:06:36.398 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a8"} update={"$set"=>{"pending_op_groups.0.pending_ops.3.state"=>:rolledback}} flags=[] (0.4742ms) (pid:2556)
>2013-01-25 07:06:36.398 [DEBUG] Rollback create_group_instance (pid:2556)
>2013-01-25 07:06:36.399 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$pull"=>{"group_instances"=>{"_id"=>"51027543032800fc090000c0"}}} flags=[] (0.3376ms) (pid:2556)
>2013-01-25 07:06:36.400 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000af"} update={"$set"=>{"pending_op_groups.0.pending_ops.12.state"=>:rolledback}} flags=[] (0.5655ms) (pid:2556)
>2013-01-25 07:06:36.402 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51027543032800fc090000a3"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.8976ms) (pid:2556)
>2013-01-25 07:06:36.405 [DEBUG] Rollback create_group_instance (pid:2556)
>2013-01-25 07:06:36.406 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$pull"=>{"group_instances"=>{"_id"=>"51027543032800fc090000bf"}}} flags=[] (0.2873ms) (pid:2556)
>2013-01-25 07:06:36.407 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3", "pending_op_groups._id"=>"51027543032800fc090000a4", "pending_op_groups.0.pending_ops._id"=>"51027543032800fc090000a7"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:rolledback}} flags=[] (0.4153ms) (pid:2556)
>2013-01-25 07:06:36.409 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"51027256032800fc09000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4468ms) (pid:2556)
>2013-01-25 07:06:36.410 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x000000069ef3a8>"=>1359115596}], "app_ids"=>"51027543032800fc090000a3"}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1359116196}}} (0.7217ms) (pid:2556)
>2013-01-25 07:06:36.411 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"51027256032800fc09000001"} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.4387ms) (pid:2556)
>2013-01-25 07:06:36.413 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3853ms) (pid:2556)
>2013-01-25 07:06:36.414 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"51027256032800fc09000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.3960ms) (pid:2556)
>2013-01-25 07:06:36.416 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=cloud_users selector={"_id"=>"51027256032800fc09000001"} update={"$set"=>{"consumed_gears"=>0, "updated_at"=>2013-01-25 12:06:36 UTC}} flags=[] (0.2866ms) (pid:2556)
>2013-01-25 07:06:36.417 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "locked"=>true, "app_ids"=>"51027543032800fc090000a3"}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.5569ms) (pid:2556)
>2013-01-25 07:06:36.418 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} update={"$pull"=>{"pending_op_groups"=>{"_id"=>"51027543032800fc090000a4"}}} flags=[] (0.3192ms) (pid:2556)
>2013-01-25 07:06:36.419 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51027256032800fc09000001", "locked"=>false, "app_ids"=>"51027543032800fc090000a3"}, :new=>true, :update=>{"$pull"=>{:app_ids=>"51027543032800fc090000a3"}}} (0.5176ms) (pid:2556)
>2013-01-25 07:06:36.420 [DEBUG] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=applications selector={"_id"=>"51027543032800fc090000a3"} flags=[:remove_first] (0.2894ms) (pid:2556)
>2013-01-25 07:06:36.420 [DEBUG] [REQ_ID=384e0dcd37ad4cb3a491983b78466a83] ACTION=ADD_APPLICATION Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:2556)
>2013-01-25 07:06:36.422 [INFO ] Completed 422 Unprocessable Entity in 9003ms (Views: 0.5ms) (pid:2556)
>
>

Actions: View

Attachments on bug 904081: 687439