Attachment 754773 Details for Bug 967504 – broker log

broker log

file_967504.txt (text/plain), 16.98 KB, created by Xiaoli Tian on 2013-05-30 10:35:49 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Xiaoli Tian

Created: 2013-05-30 10:35:49 UTC

Size: 16.98 KB

patch

obsolete

>013-05-30 06:22:15.160 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51a728444efd7ff39d000007", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, {"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000009", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000a", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51a728444efd7ff39d000009"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000b", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:reserve_uid, "prereq"=>["51a728444efd7ff39d00000a"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000c", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:create_gear, "prereq"=>["51a728444efd7ff39d00000b"], "retry_count"=>0, "retry_rollback_op"=>"51a728444efd7ff39d00000b", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000014", "args"=>{"user_id"=>"51a727fd4efd7ff39d000001", "parent_user_id"=>nil, "app_name"=>"railsapp", "gear_ref"=>"51a728444efd7ff39d000005", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51a728444efd7ff39d00000c"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000d", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:register_dns, "prereq"=>["51a728444efd7ff39d00000c"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000015", "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:update_configuration, "prereq"=>["51a728444efd7ff39d00000d"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000e", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "cartridge_vendor"=>"redhat", "version"=>"1.9"}, "op_type"=>:new_component, "prereq"=>["51a728444efd7ff39d000009"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000f", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "init_git_url"=>"git://github.com/openshift/rails-example.git"}, "op_type"=>:add_component, "prereq"=>["51a728444efd7ff39d00000e", "51a728444efd7ff39d00000d"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000010", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:post_configure_component, "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "init_git_url"=>"git://github.com/openshift/rails-example.git"}, "prereq"=>["51a728444efd7ff39d00000f", "51a728444efd7ff39d00000d", "51a728444efd7ff39d000016"]}, {"_id"=>"51a728444efd7ff39d000011", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "cartridge_vendor"=>"redhat", "version"=>"5.1"}, "op_type"=>:new_component, "prereq"=>["51a728444efd7ff39d000009", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000012", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "init_git_url"=>nil}, "op_type"=>:add_component, "prereq"=>["51a728444efd7ff39d000011", "51a728444efd7ff39d00000d", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000013", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "init_git_url"=>nil}, "op_type"=>:post_configure_component, "prereq"=>["51a728444efd7ff39d000012", "51a728444efd7ff39d00000d", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000016", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["51a728444efd7ff39d000007", "51a728444efd7ff39d000009", "51a728444efd7ff39d00000a", "51a728444efd7ff39d00000b", "51a728444efd7ff39d00000c", "51a728444efd7ff39d000014", "51a728444efd7ff39d00000d", "51a728444efd7ff39d000015", "51a728444efd7ff39d00000e", "51a728444efd7ff39d00000f", "51a728444efd7ff39d000011", "51a728444efd7ff39d000012", "51a728444efd7ff39d000013"]}]}} flags=[] (pid:4875)
>2013-05-30 06:22:15.160 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.4675ms) (pid:4875)
>2013-05-30 06:22:15.167 [DEBUG] Execute execute_connections (pid:4875)
>2013-05-30 06:22:15.169 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$set"=>{"pending_op_groups.0.pending_ops.14.state"=>:completed}} flags=[] (pid:4875)
>2013-05-30 06:22:15.169 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7188ms) (pid:4875)
>2013-05-30 06:22:15.171 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51a728444efd7ff39d000005"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (1.3881ms) (pid:4875)
>2013-05-30 06:22:15.183 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"51a728444efd7ff39d000007", "args"=>{"group_overrides"=>[{"components"=>[{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, {"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[]}, "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000009", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017"}, "op_type"=>:create_group_instance, "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000a", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "host_singletons"=>true, "app_dns"=>true}, "op_type"=>:init_gear, "prereq"=>["51a728444efd7ff39d000009"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000b", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:reserve_uid, "prereq"=>["51a728444efd7ff39d00000a"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000c", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:create_gear, "prereq"=>["51a728444efd7ff39d00000b"], "retry_count"=>0, "retry_rollback_op"=>"51a728444efd7ff39d00000b", "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000014", "args"=>{"user_id"=>"51a727fd4efd7ff39d000001", "parent_user_id"=>nil, "app_name"=>"railsapp", "gear_ref"=>"51a728444efd7ff39d000005", "event"=>"begin", "usage_type"=>"GEAR_USAGE", "gear_size"=>"small"}, "op_type"=>:track_usage, "prereq"=>["51a728444efd7ff39d00000c"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000d", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:register_dns, "prereq"=>["51a728444efd7ff39d00000c"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000015", "args"=>{"add_keys_attrs"=>[], "add_env_vars"=>[], "group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005"}, "op_type"=>:update_configuration, "prereq"=>["51a728444efd7ff39d00000d"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000e", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "cartridge_vendor"=>"redhat", "version"=>"1.9"}, "op_type"=>:new_component, "prereq"=>["51a728444efd7ff39d000009"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d00000f", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "init_git_url"=>"git://github.com/openshift/rails-example.git"}, "op_type"=>:add_component, "prereq"=>["51a728444efd7ff39d00000e", "51a728444efd7ff39d00000d"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000010", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:post_configure_component, "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"ruby-1.9", "cart"=>"ruby-1.9"}, "init_git_url"=>"git://github.com/openshift/rails-example.git"}, "prereq"=>["51a728444efd7ff39d00000f", "51a728444efd7ff39d00000d", "51a728444efd7ff39d000016"]}, {"_id"=>"51a728444efd7ff39d000011", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "cartridge_vendor"=>"redhat", "version"=>"5.1"}, "op_type"=>:new_component, "prereq"=>["51a728444efd7ff39d000009", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000012", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "init_git_url"=>nil}, "op_type"=>:add_component, "prereq"=>["51a728444efd7ff39d000011", "51a728444efd7ff39d00000d", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000013", "args"=>{"group_instance_id"=>"51a728444efd7ff39d000017", "gear_id"=>"51a728444efd7ff39d000005", "comp_spec"=>{"comp"=>"mysql-5.1", "cart"=>"mysql-5.1"}, "init_git_url"=>nil}, "op_type"=>:post_configure_component, "prereq"=>["51a728444efd7ff39d000012", "51a728444efd7ff39d00000d", "51a728444efd7ff39d00000f"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}, {"_id"=>"51a728444efd7ff39d000016", "op_type"=>:execute_connections, "prereq"=>["51a728444efd7ff39d000007", "51a728444efd7ff39d000009", "51a728444efd7ff39d00000a", "51a728444efd7ff39d00000b", "51a728444efd7ff39d00000c", "51a728444efd7ff39d000014", "51a728444efd7ff39d00000d", "51a728444efd7ff39d000015", "51a728444efd7ff39d00000e", "51a728444efd7ff39d00000f", "51a728444efd7ff39d000011", "51a728444efd7ff39d000012", "51a728444efd7ff39d000013"], "retry_count"=>0, "saved_values"=>[], "state"=>:completed}]}} flags=[] (pid:4875)
>2013-05-30 06:22:15.183 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.4641ms) (pid:4875)
>2013-05-30 06:22:15.190 [DEBUG] Execute post_configure_component (pid:4875)
>2013-05-30 06:22:15.192 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.9", :action=>"post-configure", :args=>{"--with-app-uuid"=>"895943249398067907002368", "--with-app-name"=>"railsapp", "--with-container-uuid"=>"895943249398067907002368", "--with-container-name"=>"railsapp", "--with-namespace"=>"domx1", "--with-request-id"=>"292a26b3bd313e15888469bf08046b1c", "--cart-name"=>"ruby-1.9", "--component-name"=>"ruby-1.9", "--with-software-version"=>"1.9", "--cartridge-vendor"=>"redhat", "--with-template-git-url"=>"git://github.com/openshift/rails-example.git"}}, ip-10-154-137-137, {'identity' => ip-10-154-137-137}) (Request ID: 292a26b3bd313e15888469bf08046b1c) (pid:4875)
>
>
>
>
>
>2013-05-30 06:25:03.918 [DEBUG] Dalli::Server#connect localhost:11212 (pid:4780)
>2013-05-30 06:25:03.117 [INFO ] Started POST "/broker/nurture" for 127.0.0.1 at 2013-05-30 06:25:03 -0400 (pid:4780)
>2013-05-30 06:25:03.131 [INFO ] Processing by BrokerController#nurture_post as XML (pid:4780)
>2013-05-30 06:25:03.131 [INFO ] Parameters: {"json_data"=>"{\"app_uuid\":\"895943249398067907002368\",\"action\":\"push\"}"} (pid:4780)
>2013-05-30 06:25:03.132 [WARN ] WARNING: Can't verify CSRF token authenticity (pid:4780)
>2013-05-30 06:25:03.133 [DEBUG] User-Agent = 'OpenShift' (pid:4780)
>2013-05-30 06:25:03.140 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (0.6566ms) (pid:4780)
>2013-05-30 06:25:03.145 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"group_instances.gears.uuid"=>"895943249398067907002368"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (3.8781ms) (pid:4780)
>2013-05-30 06:25:03.215 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$set"=>{"analytics"=>{"user_agent"=>"openshift_console/1.9.9 (ruby 1.9.3; x86_64-linux)", "push"=>"2013-05-30 06:25:03"}, "updated_at"=>2013-05-30 10:25:03 UTC}} flags=[] (pid:4780)
>2013-05-30 06:25:03.220 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.7307ms) (pid:4780)
>2013-05-30 06:25:03.221 [INFO ] Completed 200 OK in 90ms (Views: 0.2ms) (pid:4780)
>2013-05-30 06:25:05.649 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000005cbcc58 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-154-137-137", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"Starting Ruby cart\nhttpd (pid 2181) already running\n", :exitcode=>0}}>] (Request ID: 292a26b3bd313e15888469bf08046b1c) (pid:4875)
>2013-05-30 06:25:05.671 [DEBUG] DEBUG: MCollective Response Time (execute_direct: post-configure): 169.875631326s  (Request ID: 292a26b3bd313e15888469bf08046b1c) (pid:4875)
>2013-05-30 06:25:05.694 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$set"=>{"pending_op_groups.0.pending_ops.10.state"=>:completed}} flags=[] (pid:4875)
>2013-05-30 06:25:05.757 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1086ms) (pid:4875)
>2013-05-30 06:25:05.818 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51a728444efd7ff39d000005"} update={"$pull"=>{"pending_op_groups"=>{"_id"=>"51a728444efd7ff39d000006"}}} flags=[] (pid:4875)
>2013-05-30 06:25:05.820 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (4.7331ms) (pid:4875)
>2013-05-30 06:25:05.839 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51a728444efd7ff39d000005"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.6444ms) (pid:4875)
>2013-05-30 06:25:05.879 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"51a728444efd7ff39d000004"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (2.3384ms) (pid:4875)
>2013-05-30 06:25:05.946 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"51a727fd4efd7ff39d000001", "locked"=>false, "app_ids.51a728444efd7ff39d000005"=>{"$exists"=>true}}, :new=>true, :update=>{"$unset"=>{"app_ids.51a728444efd7ff39d000005"=>""}}} (4.5910ms) (pid:4875)
>2013-05-30 06:25:05.955 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={:_id=>"51a728444efd7ff39d000004"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.3791ms) (pid:4875)
>2013-05-30 06:25:05.119 [DEBUG] SUCCESS ACTION=ADD_APPLICATION USER_ID=51a727fd4efd7ff39d000001 LOGIN=xtian+test1@redhat.com APP=railsapp DOMAIN=domx1 APP_UUID=895943249398067907002368 Application railsapp was created. Application railsapp was created., MySQL 5.1 database added.  Please make note of these credentials:
>       Root User: adminRD6YLti
>   Root Password: p1m8ELqzfUA-
>   Database Name: railsapp
>Connection URL: mysql://$OPENSHIFT_MYSQL_DB_HOST:$OPENSHIFT_MYSQL_DB_PORT/
>You can manage your new MySQL database by also embedding phpmyadmin-3.4.
>The phpmyadmin username and password will be the same as the MySQL credentials above. (pid:4875)
>2013-05-30 06:25:05.139 [INFO ] Completed 201 Created in 188562ms (Views: 14.4ms) (pid:4875)

Actions: View

Attachments on bug 967504: 754773 | 754774 | 754779 | 754781