Attachment 730198 Details for Bug 946987 – development.log

development.log

development.log (text/x-log), 118.62 KB, created by Wei Sun on 2013-04-01 06:22:01 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Wei Sun

Created: 2013-04-01 06:22:01 UTC

Size: 118.62 KB

patch

obsolete

>[0;37m2013-04-01 01:20:03.536[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=cloud_users selector={"_id"=>"5159123e78beb22547000001"} update={"$set"=>{"consumed_gears"=>0, "updated_at"=>2013-04-01 05:20:03 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:20:03.537[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5975ms) (pid:3238)
>[0;37m2013-04-01 01:20:03.549[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "locked"=>true, "app_ids.515918f278beb2254700011a"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.6008ms) (pid:3238)
>[0;37m2013-04-01 01:20:03.623[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"515918f278beb2254700011a"} update={"$pull"=>{"pending_op_groups"=>{"_id"=>"515918f278beb2254700011b"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:20:03.625[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4480ms) (pid:3238)
>[0;37m2013-04-01 01:20:03.639[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "locked"=>false, "app_ids.515918f278beb2254700011a"=>{"$exists"=>true}}, :new=>true, :update=>{"$unset"=>{"app_ids.515918f278beb2254700011a"=>""}}} (0.6006ms) (pid:3238)
>[0;37m2013-04-01 01:20:03.649[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=applications selector={"_id"=>"515918f278beb2254700011a"} flags=[:remove_first] (pid:3238)
>[0;37m2013-04-01 01:20:03.721[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5476ms) (pid:3238)
>[0;37m2013-04-01 01:20:03.727[0m [[0;37mDEBUG[0m] SUCCESS ACTION=ADD_APPLICATION USER_ID=5159123e78beb22547000001 LOGIN=wsun@redhat.com DOMAIN=wsundevv2auto Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:3238)
>[0;37m2013-04-01 01:20:03.744[0m [[32mINFO [0m] Completed 422 Unprocessable Entity in 16403ms (Views: 0.5ms) (pid:3238)
>[0;37m2013-04-01 01:26:19.492[0m [[32mINFO [0m] Started GET "/broker/rest/api" for 203.114.244.88 at 2013-04-01 01:26:19 -0400 (pid:3238)
>[0;37m2013-04-01 01:26:19.494[0m [[32mINFO [0m] Processing by ApiController#show as JSON (pid:3238)
>[0;37m2013-04-01 01:26:19.502[0m [[32mINFO [0m] Completed 200 OK in 8ms (Views: 4.3ms) (pid:3238)
>[0;37m2013-04-01 01:26:19.806[0m [[32mINFO [0m] Started GET "/broker/rest/cartridges" for 203.114.244.88 at 2013-04-01 01:26:19 -0400 (pid:3238)
>[0;37m2013-04-01 01:26:19.807[0m [[32mINFO [0m] Processing by CartridgesController#index as JSON (pid:3238)
>[0;37m2013-04-01 01:26:19.812[0m [[0;37mDEBUG[0m] SUCCESS ACTION=LIST_CARTRIDGES USER_ID= LOGIN= List all cartridges (pid:3238)
>[0;37m2013-04-01 01:26:19.873[0m [[32mINFO [0m] Completed 200 OK in 66ms (Views: 59.9ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.197[0m [[32mINFO [0m] Started GET "/broker/rest/domains" for 203.114.244.88 at 2013-04-01 01:26:20 -0400 (pid:3238)
>[0;37m2013-04-01 01:26:20.198[0m [[32mINFO [0m] Processing by DomainsController#index as JSON (pid:3238)
>[0;37m2013-04-01 01:26:20.203[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (4.4470ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.205[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"ff81439f6de259434eae34f4f6a79cdd83ac68c273358e0ea0c2ebfc64867345"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.5896ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.206[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.4048ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.207[0m [[0;37mDEBUG[0m] SUCCESS ACTION=AUTHENTICATE USER_ID=5159123e78beb22547000001 LOGIN=wsun@redhat.com IP=203.114.244.88 SCOPES=session Authenticated (pid:3238)
>[0;37m2013-04-01 01:26:20.208[0m [[0;37mDEBUG[0m] Getting domains for user wsun@redhat.com (pid:3238)
>[0;37m2013-04-01 01:26:20.209[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"5159123e78beb22547000001"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (0.4447ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.212[0m [[0;37mDEBUG[0m] SUCCESS ACTION=LIST_DOMAINS USER_ID=5159123e78beb22547000001 LOGIN=wsun@redhat.com (pid:3238)
>[0;37m2013-04-01 01:26:20.216[0m [[32mINFO [0m] Completed 200 OK in 18ms (Views: 3.5ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.525[0m [[32mINFO [0m] Started POST "/broker/rest/domains/wsundevv2auto/applications" for 203.114.244.88 at 2013-04-01 01:26:20 -0400 (pid:3238)
>[0;37m2013-04-01 01:26:20.528[0m [[32mINFO [0m] Processing by ApplicationsController#create as JSON (pid:3238)
>[0;37m2013-04-01 01:26:20.528[0m [[32mINFO [0m] Parameters: {"name"=>"phpt", "cartridges"=>["php-5.3"], "domain_id"=>"wsundevv2auto", "application"=>{"name"=>"phpt"}} (pid:3238)
>[0;37m2013-04-01 01:26:20.530[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=authorizations selector={"$query"=>{"token"=>"ff81439f6de259434eae34f4f6a79cdd83ac68c273358e0ea0c2ebfc64867345"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.7482ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.531[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.3548ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.532[0m [[0;37mDEBUG[0m] SUCCESS ACTION=AUTHENTICATE USER_ID=5159123e78beb22547000001 LOGIN=wsun@redhat.com IP=203.114.244.88 SCOPES=session Authenticated (pid:3238)
>[0;37m2013-04-01 01:26:20.533[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"owner_id"=>"5159123e78beb22547000001", "canonical_namespace"=>"wsundevv2auto"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.5088ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.534[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.3459ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.535[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:count=>"applications", :query=>{"domain_id"=>"5159124a78beb22547000004", "canonical_name"=>"phpt"}} (0.4225ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.535[0m [[0;37mDEBUG[0m] Checking to see if user limit for number of apps has been reached (pid:3238)
>[0;37m2013-04-01 01:26:20.541[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=applications documents=[{"_id"=>"51591a7c78beb2254700012f", "uuid"=>"262763926303334769623040", "domain_requires"=>[], "group_overrides"=>[], "user_ids"=>[], "component_start_order"=>[], "component_stop_order"=>[], "component_configure_order"=>[], "init_git_url"=>nil, "analytics"=>{}, "canonical_name"=>"phpt", "name"=>"phpt", "default_gear_size"=>"small", "scalable"=>false, "domain_id"=>"5159124a78beb22547000004", "updated_at"=>2013-04-01 05:26:20 UTC, "created_at"=>2013-04-01 05:26:20 UTC}] flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.541[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7069ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.543[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"analytics"=>{"user_agent"=>"rhc/1.6.8 (ruby 1.9.3; x86_64-linux) (2.3.2, ruby 1.9.3 (2013-02-06) [x86_64-linux])"}, "updated_at"=>2013-04-01 05:26:20 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.543[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5498ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.547[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "$or"=>[{"app_ids.51591a7c78beb2254700012f"=>{"$exists"=>false}}, {"app_ids.51591a7c78beb2254700012f"=>{"$lt"=>1364793980}}]}, :new=>true, :update=>{"$set"=>{"app_ids.51591a7c78beb2254700012f"=>1364794580}}} (0.6001ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.549[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$push"=>{"pending_op_groups"=>{"_id"=>"51591a7c78beb22547000130", "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.6.8 (ruby 1.9.3; x86_64-linux) (2.3.2, ruby 1.9.3 (2013-02-06) [x86_64-linux])", "op_type"=>:add_features, "args"=>{"features"=>["php-5.3"], "group_overrides"=>[], "init_git_url"=>nil}, "parent_op_id"=>nil, "updated_at"=>2013-04-01 05:26:20 UTC, "created_at"=>2013-04-01 05:26:20 UTC}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.549[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6776ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.550[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51591a7c78beb2254700012f"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.4523ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.553[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"5159124a78beb22547000004"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.3428ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.554[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.3543ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.555[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"_id"=>"5159123e78beb22547000001"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (0.3259ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.560[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.3779ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.561[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x00000006982be0>"=>1364793980}], "app_ids.51591a7c78beb2254700012f"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1364794580}}} (0.5181ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.562[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"5159123e78beb22547000001"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.3307ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.602[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$pushAll"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}}, {"_id"=>"51591a7c78beb22547000133", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_group_instance, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}}, {"_id"=>"51591a7c78beb22547000134", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:init_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb22547000135", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000134"]}, {"_id"=>"51591a7c78beb22547000136", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000135"], "retry_rollback_op"=>"51591a7c78beb22547000135"}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{:connections=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.603[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (32.7034ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.611[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.num_gears_added"=>1, "pending_op_groups.0.updated_at"=>2013-04-01 05:26:20 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.611[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4900ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.614[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=cloud_users selector={"_id"=>"5159123e78beb22547000001"} update={"$set"=>{"consumed_gears"=>1, "updated_at"=>2013-04-01 05:26:20 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.614[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4156ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.615[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "locked"=>true, "app_ids.51591a7c78beb2254700012f"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.5219ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.617[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0381ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.627[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}}, {"_id"=>"51591a7c78beb22547000133", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_group_instance, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}}, {"_id"=>"51591a7c78beb22547000134", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:init_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb22547000135", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000134"]}, {"_id"=>"51591a7c78beb22547000136", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000135"], "retry_rollback_op"=>"51591a7c78beb22547000135"}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.627[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1306ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.636[0m [[0;37mDEBUG[0m] Execute set_group_overrides (pid:3238)
>[0;37m2013-04-01 01:26:20.641[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}], "updated_at"=>2013-04-01 05:26:20 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.641[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5984ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.642[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.642[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5209ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.643[0m [[0;37mDEBUG[0m] Execute create_group_instance (pid:3238)
>[0;37m2013-04-01 01:26:20.644[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$push"=>{"group_instances"=>{"_id"=>"51591a7c78beb2254700013d"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.644[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4632ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.645[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.645[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5121ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.647[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0710ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.657[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:init_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb22547000135", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000134"]}, {"_id"=>"51591a7c78beb22547000136", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000135"], "retry_rollback_op"=>"51591a7c78beb22547000135"}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:new_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "prereq"=>["51591a7c78beb22547000133"]}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.657[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.2083ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.666[0m [[0;37mDEBUG[0m] Execute init_gear (pid:3238)
>[0;37m2013-04-01 01:26:20.669[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$push"=>{"group_instances.0.gears"=>{"_id"=>"51591a7c78beb2254700012f", "uuid"=>"262763926303334769623040", "name"=>"phpt", "host_singletons"=>true, "app_dns"=>true}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.669[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5918ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.674[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.2.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.674[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5174ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.674[0m [[0;37mDEBUG[0m] Execute new_component (pid:3238)
>[0;37m2013-04-01 01:26:20.676[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$push"=>{"component_instances"=>{"_id"=>"51591a7c78beb22547000141", "component_properties"=>{}, "cartridge_name"=>"php-5.3", "component_name"=>"php-5.3", "group_instance_id"=>"51591a7c78beb2254700013d"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.676[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4687ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.677[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.8.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.677[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5195ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.679[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0719ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.689[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:reserve_uid, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000134"]}, {"_id"=>"51591a7c78beb22547000136", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000135"], "retry_rollback_op"=>"51591a7c78beb22547000135"}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:20.689[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1072ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.698[0m [[0;37mDEBUG[0m] Execute reserve_uid (pid:3238)
>[0;37m2013-04-01 01:26:20.699[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=districts selector={} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (0.2902ms) (pid:3238)
>[0;37m2013-04-01 01:26:20.699[0m [[0;37mDEBUG[0m] DEBUG: rpc_get_fact: fact=active_capacity (pid:3238)
>[0;37m2013-04-01 01:26:20.702[0m [[0;37mDEBUG[0m] DEBUG: rpc_exec: rpc_client=#<MCollective::RPC::Client:0x00000006e8be98> (pid:3238)
>[0;37m2013-04-01 01:26:22.792[0m [[0;37mDEBUG[0m] Current server: ip-10-145-184-212 active capacity: 0.0 (pid:3238)
>[0;37m2013-04-01 01:26:22.793[0m [[0;37mDEBUG[0m] DEBUG: find_available_impl: current_server: ip-10-145-184-212: 0.0 (pid:3238)
>[0;37m2013-04-01 01:26:22.795[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_instances.0.gears.0.server_identity"=>"ip-10-145-184-212"}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:22.795[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.3740ms) (pid:3238)
>[0;37m2013-04-01 01:26:22.862[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_instances.0.gears.0.uid"=>nil}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:22.863[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6723ms) (pid:3238)
>[0;37m2013-04-01 01:26:22.864[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.3.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:22.865[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.4236ms) (pid:3238)
>[0;37m2013-04-01 01:26:22.867[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.1463ms) (pid:3238)
>[0;37m2013-04-01 01:26:22.878[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:create_gear, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000135"], "retry_rollback_op"=>"51591a7c78beb22547000135"}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:22.879[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1659ms) (pid:3238)
>[0;37m2013-04-01 01:26:22.887[0m [[0;37mDEBUG[0m] Execute create_gear (pid:3238)
>[0;37m2013-04-01 01:26:22.890[0m [[0;37mDEBUG[0m] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-create", :args=>{"--with-app-uuid"=>"262763926303334769623040", "--with-app-name"=>"phpt", "--with-container-uuid"=>"262763926303334769623040", "--with-container-name"=>"phpt", "--with-namespace"=>"wsundevv2auto", "--with-request-id"=>"648085f66a3a08fde389e28a012759a7", "--cart-name"=>"openshift-origin-node"}}, ip-10-145-184-212, {'identity' => ip-10-145-184-212}) (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:24.226[0m [[0;37mDEBUG[0m] DEBUG: [#<MCollective::RPC::Result:0x00000006b90f40 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-145-184-212", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:24.230[0m [[0;37mDEBUG[0m] DEBUG: MCollective Response Time (execute_direct: app-create): 1.342617598s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:24.232[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$inc"=>{"pending_op_groups.0.num_gears_created"=>1}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.232[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1766ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.233[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.4.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.233[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6056ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.236[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.5147ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.247[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000139", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb22547000137", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:register_dns, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000136"]}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.247[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1196ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.255[0m [[0;37mDEBUG[0m] Execute track_usage (pid:3238)
>[0;37m2013-04-01 01:26:24.257[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage_records documents=[{"_id"=>"51591a8078beb22547000142", "event"=>"begin", "time"=>2013-04-01 05:26:24 UTC, "created_at"=>2013-04-01 05:26:24 UTC, "gear_id"=>"51591a7c78beb2254700012f", "usage_type"=>"GEAR_USAGE", "user_id"=>"5159123e78beb22547000001", "app_name"=>"phpt", "gear_size"=>"small", "updated_at"=>2013-04-01 05:26:24 UTC}] flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.258[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6154ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.260[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=usage documents=[{"_id"=>"51591a8078beb22547000143", "user_id"=>"5159123e78beb22547000001", "app_name"=>"phpt", "gear_id"=>"51591a7c78beb2254700012f", "begin_time"=>2013-04-01 05:26:24 UTC, "created_at"=>2013-04-01 05:26:24 UTC, "usage_type"=>"GEAR_USAGE", "gear_size"=>"small", "updated_at"=>2013-04-01 05:26:24 UTC}] flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.260[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5200ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.261[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.5.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:24.261[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5689ms) (pid:3238)
>[0;37m2013-04-01 01:26:24.262[0m [[0;37mDEBUG[0m] Execute register_dns (pid:3238)
>[0;37m2013-04-01 01:26:24.263[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Login with path: /REST/Session/ (pid:3238)
>[0;37m2013-04-01 01:26:24.912[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {"token": "Pbkq2WgQtH15aGCoNFQtwlmpoNhBq5BSN5Jj9lfllxFty9RdHLDug8onb3hDDhqFp1tFLYjW9pvxEskwX3LmQWRqMfZg2ryu+Jzm9ip7q0KUPjxhpoVlhKB8HsJMf0bx3vRlXs1nG6nqvsZjnHTjbtldIGq4Czgc930lmW2VjVI=", "version": "3.3.8"}, "job_id": 309499766, "msgs": [{"INFO": "login: Login successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:24.913[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {"token"=>"Pbkq2WgQtH15aGCoNFQtwlmpoNhBq5BSN5Jj9lfllxFty9RdHLDug8onb3hDDhqFp1tFLYjW9pvxEskwX3LmQWRqMfZg2ryu+Jzm9ip7q0KUPjxhpoVlhKB8HsJMf0bx3vRlXs1nG6nqvsZjnHTjbtldIGq4Czgc930lmW2VjVI=", "version"=>"3.3.8"} (pid:3238)
>[0;37m2013-04-01 01:26:24.913[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_login): 0.650284311s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:24.979[0m [[0;37mDEBUG[0m] DEBUG: Public ip being configured 'ec2-54-234-63-118.compute-1.amazonaws.com' to app 'phpt' (pid:3238)
>[0;37m2013-04-01 01:26:24.980[0m [[0;37mDEBUG[0m] DEBUG: DYNECT put/post with path: /REST/CNAMERecord/rhcloud.com/phpt-wsundevv2auto.dev.rhcloud.com/ json data: {"rdata":{"cname":"ec2-54-234-63-118.compute-1.amazonaws.com"},"ttl":"60"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:25.724[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {"zone": "rhcloud.com", "ttl": 60, "fqdn": "phpt-wsundevv2auto.dev.rhcloud.com", "record_type": "CNAME", "rdata": {"cname": "ec2-54-234-63-118.compute-1.amazonaws.com."}, "record_id": 0}, "job_id": 309499774, "msgs": [{"INFO": "add: Record added", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:25.724[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {"zone"=>"rhcloud.com", "ttl"=>60, "fqdn"=>"phpt-wsundevv2auto.dev.rhcloud.com", "record_type"=>"CNAME", "rdata"=>{"cname"=>"ec2-54-234-63-118.compute-1.amazonaws.com."}, "record_id"=>0} (pid:3238)
>[0;37m2013-04-01 01:26:25.724[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_put_post): 0.74419718s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:25.724[0m [[0;37mDEBUG[0m] DEBUG: DYNECT put/post with path: /REST/Zone/rhcloud.com/ json data: {"publish":"true"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:28.533[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "increment", "serial": 4970847, "zone": "rhcloud.com"}, "job_id": 309499785, "msgs": [{"INFO": "publish: rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:28.535[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"increment", "serial"=>4970847, "zone"=>"rhcloud.com"} (pid:3238)
>[0;37m2013-04-01 01:26:28.536[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_put_post): 2.329013473s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:28.538[0m [[0;37mDEBUG[0m] DEBUG: DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:28.467[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {}, "job_id": 309499811, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:28.467[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {} (pid:3238)
>[0;37m2013-04-01 01:26:28.467[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_delete): 0.414187936s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:28.469[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.6.state"=>:completed}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:28.469[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.8533ms) (pid:3238)
>[0;37m2013-04-01 01:26:28.471[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0972ms) (pid:3238)
>[0;37m2013-04-01 01:26:28.481[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:28.482[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1830ms) (pid:3238)
>[0;37m2013-04-01 01:26:28.488[0m [[0;37mDEBUG[0m] Execute update_configuration (pid:3238)
>[0;37m2013-04-01 01:26:28.489[0m [[0;37mDEBUG[0m] Execute add_component (pid:3238)
>[0;37m2013-04-01 01:26:28.491[0m [[0;37mDEBUG[0m] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"php-5.3", :action=>"configure", :args=>{"--with-app-uuid"=>"262763926303334769623040", "--with-app-name"=>"phpt", "--with-container-uuid"=>"262763926303334769623040", "--with-container-name"=>"phpt", "--with-namespace"=>"wsundevv2auto", "--with-request-id"=>"648085f66a3a08fde389e28a012759a7", "--cart-name"=>"php-5.3"}}, ip-10-145-184-212, {'identity' => ip-10-145-184-212}) (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:30.209[0m [[0;37mDEBUG[0m] DEBUG: [#<MCollective::RPC::Result:0x00000004922008 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-145-184-212", :statuscode=>1, :statusmsg=>"cartridge_do_action failed -1. Output Shell command '/sbin/runuser -m -s /bin/sh 262763926303334769623040 -c \"exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c0,c501' /bin/sh -c \\\"/var/lib/openshift/262763926303334769623040/redhat-php/bin/setup --version 5.3\\\"\"' returned an error. rc=1", :data=>{:time=>nil, :output=>"Shell command '/sbin/runuser -m -s /bin/sh 262763926303334769623040 -c \"exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c0,c501' /bin/sh -c \\\"/var/lib/openshift/262763926303334769623040/redhat-php/bin/setup --version 5.3\\\"\"' returned an error. rc=1", :exitcode=>-1}}>] (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:30.211[0m [[0;37mDEBUG[0m] DEBUG: MCollective Response Time (execute_direct: configure): 1.720937383s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:30.211[0m [[0;37mDEBUG[0m] DEBUG: server results: Shell command '/sbin/runuser -m -s /bin/sh 262763926303334769623040 -c "exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c0,c501' /bin/sh -c \"/var/lib/openshift/262763926303334769623040/redhat-php/bin/setup --version 5.3\""' returned an error. rc=1 (pid:3238)
>[0;37m2013-04-01 01:26:30.212[0m [[31mERROR[0m] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:3238)
>[0;37m2013-04-01 01:26:30.212[0m [[31mERROR[0m] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.7.1/lib/openshift/mcollective_application_container_proxy.rb:2535:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.7.1/lib/openshift/mcollective_application_container_proxy.rb:2683: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.7.1/lib/openshift/mcollective_application_container_proxy.rb:696:in `configure_cartridge'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/gear.rb:122:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:185:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:146:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:146:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:1096:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:392:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:1138:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:390:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:154:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/controllers/applications_controller.rb:149: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__4471477388874778012__process_action__1409311243078747948__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_311'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/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_311'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__4471477388874778012__process_action__1409311243078747948__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__4371681195635023069__call__400678350239580758__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:3238)
>[0;37m2013-04-01 01:26:30.212[0m [[31mERROR[0m] Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:3238)
>[0;37m2013-04-01 01:26:30.213[0m [[0;37mDEBUG[0m] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.7.1/lib/openshift/mcollective_application_container_proxy.rb:2535:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.7.1/lib/openshift/mcollective_application_container_proxy.rb:2683: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.7.1/lib/openshift/mcollective_application_container_proxy.rb:696:in `configure_cartridge'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/gear.rb:122:in `add_component'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:185:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:146:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/pending_app_op_group.rb:146:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:1096:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:392:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:1138:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:390:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/models/application.rb:154:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/app/controllers/applications_controller.rb:149: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__4471477388874778012__process_action__1409311243078747948__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_311'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.7.1/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_311'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__4471477388874778012__process_action__1409311243078747948__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__4371681195635023069__call__400678350239580758__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:3238)
>[0;37m2013-04-01 01:26:30.218[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (4.0314ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.230[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:30.230[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.2951ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.237[0m [[0;37mDEBUG[0m] Rollback set_group_overrides (pid:3238)
>[0;37m2013-04-01 01:26:30.243[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_overrides"=>[], "updated_at"=>2013-04-01 05:26:30 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:30.243[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5667ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.244[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:30.244[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5577ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.245[0m [[0;37mDEBUG[0m] Rollback track_usage (pid:3238)
>[0;37m2013-04-01 01:26:30.246[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage_records selector={"$query"=>{"user_id"=>"5159123e78beb22547000001", "gear_id"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{"time"=>-1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.7236ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.249[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage_records selector={"_id"=>"51591a8078beb22547000142"} flags=[:remove_first] (pid:3238)
>[0;37m2013-04-01 01:26:30.249[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.8045ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.250[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=usage selector={"$query"=>{"user_id"=>"5159123e78beb22547000001", "gear_id"=>"51591a7c78beb2254700012f", "usage_type"=>"GEAR_USAGE"}, "$orderby"=>{"begin_time"=>-1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.4909ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.251[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=usage selector={"_id"=>"51591a8078beb22547000143"} flags=[:remove_first] (pid:3238)
>[0;37m2013-04-01 01:26:30.251[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4628ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.252[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.5.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:30.253[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5381ms) (pid:3238)
>[0;37m2013-04-01 01:26:30.253[0m [[0;37mDEBUG[0m] Rollback register_dns (pid:3238)
>[0;37m2013-04-01 01:26:30.253[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Login with path: /REST/Session/ (pid:3238)
>[0;37m2013-04-01 01:26:30.893[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {"token": "EYpI9LZYyCIB40w2JSah5vZTzZcx62rW2ymTgFx/jnN49iStJlMV+6OaEdUNxE+NlKm1LEsrmgU9H4UmO3Ul9zdeGrqBV6ZV99iKI6bbiwlJhDnu8eCmzqYv6a25Y0E6hV2oqEXgh8rLMThgTTVk9krGH1ddveeK", "version": "3.3.8"}, "job_id": 309499842, "msgs": [{"INFO": "login: Login successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:30.893[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {"token"=>"EYpI9LZYyCIB40w2JSah5vZTzZcx62rW2ymTgFx/jnN49iStJlMV+6OaEdUNxE+NlKm1LEsrmgU9H4UmO3Ul9zdeGrqBV6ZV99iKI6bbiwlJhDnu8eCmzqYv6a25Y0E6hV2oqEXgh8rLMThgTTVk9krGH1ddveeK", "version"=>"3.3.8"} (pid:3238)
>[0;37m2013-04-01 01:26:30.894[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_login): 0.640106603s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:30.894[0m [[0;37mDEBUG[0m] DEBUG: DYNECT delete with path: /REST/CNAMERecord/rhcloud.com/phpt-wsundevv2auto.dev.rhcloud.com/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:31.453[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {}, "job_id": 309499846, "msgs": [{"INFO": "delete: 1 records deleted", "SOURCE": "API-B", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:31.453[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {} (pid:3238)
>[0;37m2013-04-01 01:26:31.453[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_delete): 0.5595613s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:31.454[0m [[0;37mDEBUG[0m] DEBUG: DYNECT put/post with path: /REST/Zone/rhcloud.com/ json data: {"publish":"true"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:33.315[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "increment", "serial": 4970849, "zone": "rhcloud.com"}, "job_id": 309499856, "msgs": [{"INFO": "publish: rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:33.315[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"increment", "serial"=>4970849, "zone"=>"rhcloud.com"} (pid:3238)
>[0;37m2013-04-01 01:26:33.315[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_put_post): 1.861149134s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:33.315[0m [[0;37mDEBUG[0m] DEBUG: DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:3238)
>[0;37m2013-04-01 01:26:33.748[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response: {"status": "success", "data": {}, "job_id": 309499886, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:3238)
>[0;37m2013-04-01 01:26:33.748[0m [[0;37mDEBUG[0m] DEBUG: DYNECT Response data: {} (pid:3238)
>[0;37m2013-04-01 01:26:33.748[0m [[0;37mDEBUG[0m] DEBUG: Dynect Response Time (dyn_delete): 0.433312663s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:33.750[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.6.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:33.750[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.8965ms) (pid:3238)
>[0;37m2013-04-01 01:26:33.750[0m [[0;37mDEBUG[0m] Rollback new_component (pid:3238)
>[0;37m2013-04-01 01:26:33.752[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$pull"=>{"component_instances"=>{"_id"=>"51591a7c78beb22547000141"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:33.752[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4466ms) (pid:3238)
>[0;37m2013-04-01 01:26:33.753[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.8.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:33.753[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5090ms) (pid:3238)
>[0;37m2013-04-01 01:26:33.755[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0605ms) (pid:3238)
>[0;37m2013-04-01 01:26:33.765[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:33.765[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1344ms) (pid:3238)
>[0;37m2013-04-01 01:26:33.771[0m [[0;37mDEBUG[0m] Rollback create_gear (pid:3238)
>[0;37m2013-04-01 01:26:33.773[0m [[0;37mDEBUG[0m] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"262763926303334769623040", "--with-app-name"=>"phpt", "--with-container-uuid"=>"262763926303334769623040", "--with-container-name"=>"phpt", "--with-namespace"=>"wsundevv2auto", "--with-request-id"=>"648085f66a3a08fde389e28a012759a7", "--cart-name"=>"openshift-origin-node"}}, ip-10-145-184-212, {'identity' => ip-10-145-184-212}) (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:35.129[0m [[0;37mDEBUG[0m] DEBUG: [#<MCollective::RPC::Result:0x00000006ad04e8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-145-184-212", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:35.145[0m [[0;37mDEBUG[0m] DEBUG: MCollective Response Time (execute_direct: app-destroy): 1.242146801s  (Request ID: 648085f66a3a08fde389e28a012759a7) (pid:3238)
>[0;37m2013-04-01 01:26:35.165[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$inc"=>{"pending_op_groups.0.num_gears_rolled_back"=>1}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.171[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1094ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.182[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.4.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.183[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5527ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.204[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.2228ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.314[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.316[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1055ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.370[0m [[0;37mDEBUG[0m] Rollback reserve_uid (pid:3238)
>[0;37m2013-04-01 01:26:35.105[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_instances.0.gears.0.server_identity"=>nil}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.106[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7167ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.107[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"group_instances.0.gears.0.uid"=>nil}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.107[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1799ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.108[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.3.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.108[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5429ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.110[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.2100ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.121[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.121[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.0996ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.127[0m [[0;37mDEBUG[0m] Rollback init_gear (pid:3238)
>[0;37m2013-04-01 01:26:35.128[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$pull"=>{"group_instances.0.gears"=>{"_id"=>"51591a7c78beb2254700012f"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.128[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5882ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.133[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.2.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.133[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5066ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.135[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51591a7c78beb2254700012f"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.0059ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.144[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51591a7c78beb22547000131", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"php-5.3", "cart"=>"php-5.3"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000133", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51591a7c78beb22547000134", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000135", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:reserve_uid, "prereq"=>["51591a7c78beb22547000134"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000136", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:create_gear, "prereq"=>["51591a7c78beb22547000135"], "retry_count"=>0, "retry_rollback_op"=>"51591a7c78beb22547000135", "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000139", "args"=>{"user_id"=>"5159123e78beb22547000001", "parent_user_id"=>nil, "app_name"=>"phpt", "gear_ref"=>"51591a7c78beb2254700012f", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb22547000137", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "op_type"=>:register_dns, "prereq"=>["51591a7c78beb22547000136"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013a", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:update_configuration, "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f"}, "prereq"=>["51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb22547000138", "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}}, "op_type"=>:new_component, "prereq"=>["51591a7c78beb22547000133"], "retry_count"=>0, "saved_values"=>[], "state"=>:rolledback}, {"_id"=>"51591a7c78beb2254700013b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:add_component, "args"=>{"group_instance_id"=>"51591a7c78beb2254700013d", "gear_id"=>"51591a7c78beb2254700012f", "comp_spec"=>{"comp"=>"php-5.3", "cart"=>"php-5.3"}, "init_git_url"=>nil}, "prereq"=>["51591a7c78beb22547000138", "51591a7c78beb22547000137"]}, {"_id"=>"51591a7c78beb2254700013c", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["51591a7c78beb22547000131", "51591a7c78beb22547000133", "51591a7c78beb22547000134", "51591a7c78beb22547000135", "51591a7c78beb22547000136", "51591a7c78beb22547000139", "51591a7c78beb22547000137", "51591a7c78beb2254700013a", "51591a7c78beb22547000138", "51591a7c78beb2254700013b"]}, {"_id"=>"51591a7c78beb2254700013e", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51591a7c78beb2254700013c"]}]}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.145[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.2026ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.150[0m [[0;37mDEBUG[0m] Rollback create_group_instance (pid:3238)
>[0;37m2013-04-01 01:26:35.151[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$pull"=>{"group_instances"=>{"_id"=>"51591a7c78beb2254700013d"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.151[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5019ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.152[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:rolledback}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.152[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4966ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.154[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"5159123e78beb22547000001"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.4847ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.155[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x00000006eb67b0>"=>1364793995}], "app_ids.51591a7c78beb2254700012f"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1364794595}}} (0.5784ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.156[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"5159123e78beb22547000001"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.3500ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.158[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=cloud_users selector={"_id"=>"5159123e78beb22547000001"} update={"$set"=>{"consumed_gears"=>0, "updated_at"=>2013-04-01 05:26:35 UTC}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.158[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4306ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.159[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "locked"=>true, "app_ids.51591a7c78beb2254700012f"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.4909ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.212[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} update={"$pull"=>{"pending_op_groups"=>{"_id"=>"51591a7c78beb22547000130"}}} flags=[] (pid:3238)
>[0;37m2013-04-01 01:26:35.213[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.4501ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.215[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"5159123e78beb22547000001", "locked"=>false, "app_ids.51591a7c78beb2254700012f"=>{"$exists"=>true}}, :new=>true, :update=>{"$unset"=>{"app_ids.51591a7c78beb2254700012f"=>""}}} (1.0688ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.216[0m [[0;37mDEBUG[0m] MOPED: 127.0.0.1:27017 DELETE       database=openshift_broker_dev collection=applications selector={"_id"=>"51591a7c78beb2254700012f"} flags=[:remove_first] (pid:3238)
>[0;37m2013-04-01 01:26:35.216[0m [[0;37mDEBUG[0m] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5245ms) (pid:3238)
>[0;37m2013-04-01 01:26:35.217[0m [[0;37mDEBUG[0m] SUCCESS ACTION=ADD_APPLICATION USER_ID=5159123e78beb22547000001 LOGIN=wsun@redhat.com DOMAIN=wsundevv2auto Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:3238)
>[0;37m2013-04-01 01:26:35.219[0m [[32mINFO [0m] Completed 422 Unprocessable Entity in 14690ms (Views: 0.6ms) (pid:3238)

Actions: View

Attachments on bug 946987: 730196 | 730198