Attachment 704091 Details for Bug 916917 – development.log

development.log

file_916917.txt (text/plain), 13.22 KB, created by Rony Gong 🔥 on 2013-03-01 09:23:20 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Rony Gong 🔥

Created: 2013-03-01 09:23:20 UTC

Size: 13.22 KB

patch

obsolete

> MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (18.2707ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :sparse=>true, :ns=>"openshift_broker_dev.applications", :key=>{:"group_instances.gears.uuid"=>1}, :name=>"group_instances.gears.uuid_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.9984ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.applications", :key=>{:domain_id=>1}, :name=>"domain_id_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6895ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.domains", :key=>{:canonical_namespace=>1}, :name=>"canonical_namespace_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (3.0088ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.domains", :key=>{:owner_id=>1}, :name=>"owner_id_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.9630ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.domains", :key=>{:user_ids=>1}, :name=>"user_ids_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5519ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.cloud_users", :key=>{:login=>1}, :name=>"login_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (3.7806ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.usage_records", :key=>{:login=>1}, :name=>"login_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.4679ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.usage", :key=>{:login=>1}, :name=>"login_1"}] flags=[]
>                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.8958ms)
>2013-03-01 03:18:06.120 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.districts", :key=>{:name=>1}, :name=>"name_1"}] flags=[] (pid:2161)
>2013-03-01 03:18:06.133 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.1535ms) (pid:2161)
>2013-03-01 03:18:06.245 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:ns=>"openshift_broker_dev.locks", :key=>{:user_id=>1}, :name=>"user_id_1"}] flags=[] (pid:2161)
>2013-03-01 03:18:06.253 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.2467ms) (pid:2161)
>2013-03-01 03:18:07.618 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"group_instances.gears.uuid"=>"513051ace5a26827c60001ff"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (11.0574ms) (pid:2161)
>2013-03-01 03:18:07.630 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"513048fbe5a26827c6000005"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (1.1694ms) (pid:2161)
>2013-03-01 03:18:07.642 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"513048e8e5a26827c6000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (6.1035ms) (pid:2161)
>2013-03-01 03:18:07.650 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"513048e8e5a26827c6000001", "$or"=>[{"app_ids.513051ace5a26827c60001ff"=>{"$exists"=>false}}, {"app_ids.513051ace5a26827c60001ff"=>{"$lt"=>1362125887}}]}, :new=>true, :update=>{"$set"=>{"app_ids.513051ace5a26827c60001ff"=>1362126487}}} (4.1242ms) (pid:2161)
>2013-03-01 03:18:09.701 [DEBUG] DEBUG: Source district uuid: 513048a7e5a26865ad000001 (pid:2161)
>2013-03-01 03:18:09.703 [DEBUG] DEBUG: Destination district uuid: 513048a7e5a26865ad000001 (pid:2161)
>2013-03-01 03:18:09.705 [DEBUG] DEBUG: District unchanged keeping uid (pid:2161)
>2013-03-01 03:18:10.298 [DEBUG] DEBUG: Getting existing app 'redmine' status before moving (pid:2161)
>2013-03-01 03:18:10.327 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x000000066aedb0> (pid:2161)
>2013-03-01 03:18:10.327 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.8", :action=>"status", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"ruby-1.8"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:11.768 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000006536758 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"CLIENT_RESULT: Total Accesses: 4\nCLIENT_RESULT: Total kBytes: 0\nCLIENT_RESULT: Uptime: 127\nCLIENT_RESULT: ReqPerSec: .0314961\nCLIENT_RESULT: BytesPerSec: 0\nCLIENT_RESULT: BytesPerReq: 0\nCLIENT_RESULT: BusyWorkers: 1\nCLIENT_RESULT: IdleWorkers: 1\nCLIENT_RESULT: Scoreboard: W_...\nATTR: quota_blocks=1048576\nATTR: quota_files=40000\n", :exitcode=>0}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:11.772 [DEBUG] DEBUG: MCollective Response Time (execute_direct: status): 1.462326975s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:11.776 [DEBUG] DEBUG: Gear component 'ruby-1.8' was running (pid:2161)
>2013-03-01 03:18:11.817 [DEBUG] DEBUG: Stopping existing app cartridge 'mysql-5.1' before moving (pid:2161)
>2013-03-01 03:18:11.823 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006bb2028> (pid:2161)
>2013-03-01 03:18:11.823 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"mysql-5.1", :action=>"stop", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"mysql-5.1"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:16.530 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000006d0cbd0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:16.530 [DEBUG] DEBUG: MCollective Response Time (execute_direct: stop): 4.710103583s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:16.539 [DEBUG] DEBUG: Stopping existing app cartridge 'ruby-1.8' before moving (pid:2161)
>2013-03-01 03:18:16.550 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x000000069807f0> (pid:2161)
>2013-03-01 03:18:16.551 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.8", :action=>"stop", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"ruby-1.8"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.164 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000067b1bb8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.172 [DEBUG] DEBUG: MCollective Response Time (execute_direct: stop): 4.630698444s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.178 [DEBUG] DEBUG: Force stopping existing app cartridge 'ruby-1.8' before moving (pid:2161)
>2013-03-01 03:18:21.181 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000005fd2aa0> (pid:2161)
>2013-03-01 03:18:21.182 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"force-stop", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"openshift-origin-node"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.297 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000006b68c70 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>1, :statusmsg=>"cartridge_do_action failed -1. Output uninitialized constant OpenShift::ApplicationContainer::ApplicationState", :data=>{:time=>nil, :output=>"uninitialized constant OpenShift::ApplicationContainer::ApplicationState", :exitcode=>-1}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.299 [DEBUG] DEBUG: MCollective Response Time (execute_direct: force-stop): 0.120300021s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.301 [DEBUG] DEBUG: server results: uninitialized constant OpenShift::ApplicationContainer::ApplicationState (pid:2161)
>2013-03-01 03:18:21.301 [DEBUG] DEBUG: Error performing force-stop on existing app on try 1: Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:2161)
>2013-03-01 03:18:21.303 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006b713e8> (pid:2161)
>2013-03-01 03:18:21.303 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"force-stop", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"openshift-origin-node"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.446 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000006b0d640 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>1, :statusmsg=>"cartridge_do_action failed -1. Output uninitialized constant OpenShift::ApplicationContainer::ApplicationState", :data=>{:time=>nil, :output=>"uninitialized constant OpenShift::ApplicationContainer::ApplicationState", :exitcode=>-1}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.450 [DEBUG] DEBUG: MCollective Response Time (execute_direct: force-stop): 0.148395904s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:21.450 [DEBUG] DEBUG: server results: uninitialized constant OpenShift::ApplicationContainer::ApplicationState (pid:2161)
>2013-03-01 03:18:21.450 [DEBUG] DEBUG: Error performing force-stop on existing app on try 2: Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:2161)
>2013-03-01 03:18:21.464 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x0000000656b8e0> (pid:2161)
>2013-03-01 03:18:21.465 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.8", :action=>"start", :args=>{"--with-app-uuid"=>"513051ace5a26827c60001ff", "--with-app-name"=>"redmine", "--with-container-uuid"=>"513051ace5a26827c60001ff", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1016, "--with-request-id"=>nil, "--cart-name"=>"ruby-1.8"}}, ip-10-147-168-174, {'identity' => ip-10-147-168-174}) (Request ID: ) (pid:2161)
>2013-03-01 03:18:28.780 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007013ba8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-168-174", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:2161)
>2013-03-01 03:18:28.781 [DEBUG] DEBUG: MCollective Response Time (execute_direct: start): 7.320434462s  (Request ID: ) (pid:2161)
>2013-03-01 03:18:28.811 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"513048e8e5a26827c6000001", "locked"=>false, "app_ids.513051ace5a26827c60001ff"=>{"$exists"=>true}}, :new=>true, :update=>{"$unset"=>{"app_ids.513051ace5a26827c60001ff"=>""}}} (12.6567ms) (pid:2161)

Actions: View

Attachments on bug 916917: 704091