Attachment 715942 Details for Bug 927181 – development.log

development.log

file_927181.txt (text/plain), 28.63 KB, created by Rony Gong 🔥 on 2013-03-25 09:43:54 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Rony Gong 🔥

Created: 2013-03-25 09:43:54 UTC

Size: 28.63 KB

patch

obsolete

>echo Agent pid 31449 killed; (pid:30809)
>2013-03-25 05:02:06.876 [DEBUG] Dalli::Server#connect localhost:11212 (pid:30809)
>2013-03-25 05:02:06.885 [INFO ] localhost:11212 failed (count: 3) (pid:30809)
>2013-03-25 05:02:06.886 [DEBUG] localhost:11212 is still down (for 59.563 seconds now) (pid:30809)
>2013-03-25 05:02:06.895 [DEBUG] down_retry_delay not reached for localhost:11212 (0.991 seconds left) (pid:30809)
>2013-03-25 05:02:06.901 [DEBUG] down_retry_delay not reached for localhost:11212 (0.984 seconds left) (pid:30809)
>2013-03-25 05:02:06.906 [DEBUG] DEBUG: Performing cartridge level move for 'ruby-1.8' on ip-10-147-199-177 (pid:30809)
>2013-03-25 05:02:06.909 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.8", :action=>"move", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--cart-name"=>"ruby-1.8", "--idle"=>false}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:02:15.152 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000003d50b30 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"Nothing found in .openshift/config/* to redeploy\n", :exitcode=>0}}>] (Request ID: ) (pid:30809)
>2013-03-25 05:02:15.154 [DEBUG] DEBUG: MCollective Response Time (execute_direct: move): 8.247174236s  (Request ID: ) (pid:30809)
>2013-03-25 05:02:15.155 [DEBUG] Dalli::Server#connect localhost:11212 (pid:30809)
>2013-03-25 05:02:15.157 [INFO ] localhost:11212 failed (count: 4) (pid:30809)
>2013-03-25 05:02:15.157 [DEBUG] localhost:11212 is still down (for 67.834 seconds now) (pid:30809)
>2013-03-25 05:02:15.165 [DEBUG] DEBUG: Performing cartridge level move for embedded mysql-5.1 for 'redmine' on ip-10-147-199-177 (pid:30809)
>2013-03-25 05:02:15.167 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"mysql-5.1", :action=>"move", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--cart-name"=>"mysql-5.1"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:02:55.645 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000004f77818 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"APP_INFO: Connection URL: mysql://127.1.246.1:3306/\n", :exitcode=>0}}>] (Request ID: ) (pid:30809)
>2013-03-25 05:02:55.650 [DEBUG] DEBUG: MCollective Response Time (execute_direct: move): 40.484994568s  (Request ID: ) (pid:30809)
>2013-03-25 05:02:55.651 [DEBUG] DEBUG: Performing cartridge level post-move for embedded mysql-5.1 for 'redmine' on ip-10-147-199-177 (pid:30809)
>2013-03-25 05:02:55.652 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"mysql-5.1", :action=>"post-move", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--cart-name"=>"mysql-5.1"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:03:33.557 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000004e426a0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:30809)
>2013-03-25 05:03:33.622 [DEBUG] DEBUG: MCollective Response Time (execute_direct: post-move): 37.410577655s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:33.629 [DEBUG] Dalli::Server#connect localhost:11212 (pid:30809)
>2013-03-25 05:03:33.622 [DEBUG] DEBUG: MCollective Response Time (execute_direct: post-move): 37.410577655s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:33.629 [DEBUG] Dalli::Server#connect localhost:11212 (pid:30809)
>2013-03-25 05:03:33.669 [INFO ] localhost:11212 failed (count: 5) (pid:30809)
>2013-03-25 05:03:33.671 [DEBUG] localhost:11212 is still down (for 145.744 seconds now) (pid:30809)
>2013-03-25 05:03:33.782 [DEBUG] down_retry_delay not reached for localhost:11212 (0.989 seconds left) (pid:30809)
>2013-03-25 05:03:33.908 [DEBUG] down_retry_delay not reached for localhost:11212 (0.976 seconds left) (pid:30809)
>2013-03-25 05:03:33.100 [DEBUG] DEBUG: Starting cartridge 'ruby-1.8' in 'redmine' after move on ip-10-147-199-177 (pid:30809)
>2013-03-25 05:03:33.101 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"ruby-1.8", :action=>"start", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--cart-name"=>"ruby-1.8"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:03:39.539 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000005856d30 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:30809)
>2013-03-25 05:03:39.542 [DEBUG] DEBUG: MCollective Response Time (execute_direct: start): 6.441621267s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:39.542 [DEBUG] Dalli::Server#connect localhost:11212 (pid:30809)
>2013-03-25 05:03:39.552 [INFO ] localhost:11212 failed (count: 6) (pid:30809)
>2013-03-25 05:03:39.552 [DEBUG] localhost:11212 is still down (for 152.229 seconds now) (pid:30809)
>2013-03-25 05:03:39.560 [DEBUG] DEBUG: Starting cartridge 'mysql-5.1' in 'redmine' after move on ip-10-147-199-177 (pid:30809)
>2013-03-25 05:03:39.561 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"mysql-5.1", :action=>"start", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--cart-name"=>"mysql-5.1"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:03:44.420 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000005916568 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: ) (pid:30809)
>2013-03-25 05:03:44.422 [DEBUG] DEBUG: MCollective Response Time (execute_direct: start): 4.861703013s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:44.422 [DEBUG] DEBUG: Fixing DNS and mongo for gear 'redmine' after move (pid:30809)
>2013-03-25 05:03:44.422 [DEBUG] DEBUG: Changing server identity of 'redmine' from 'ip-10-152-179-118' to 'ip-10-147-199-177' (pid:30809)
>2013-03-25 05:03:44.424 [DEBUG] DEBUG: DYNECT Login with path: /REST/Session/ (pid:30809)
>2013-03-25 05:03:49.146 [DEBUG] DEBUG: DYNECT Response: {"status": "success", "data": {"token": "u/05qkG4rENyuZFrrpOJ4YIT6B/M8UNYZ3w8fGN4cvJwyrU7W51ShSD70MAGLea/+JZN2lJMWh3gDPvV1edSlHoZg0vV0pHync8dNlDff145PD4rHcdLeM7wktnlNaV8qyGT9TiWXXPQIqQFeOket0KQn+H/Iupj", "version": "3.3.8"}, "job_id": 303445485, "msgs": [{"INFO": "login: Login successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:30809)
>2013-03-25 05:03:49.147 [DEBUG] DEBUG: DYNECT Response data: {"token"=>"u/05qkG4rENyuZFrrpOJ4YIT6B/M8UNYZ3w8fGN4cvJwyrU7W51ShSD70MAGLea/+JZN2lJMWh3gDPvV1edSlHoZg0vV0pHync8dNlDff145PD4rHcdLeM7wktnlNaV8qyGT9TiWXXPQIqQFeOket0KQn+H/Iupj", "version"=>"3.3.8"} (pid:30809)
>2013-03-25 05:03:49.147 [DEBUG] DEBUG: Dynect Response Time (dyn_login): 4.722748934s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:49.231 [DEBUG] DEBUG: Public ip being modified 'ec2-23-21-17-108.compute-1.amazonaws.com' to app 'redmine' (pid:30809)
>2013-03-25 05:03:49.231 [DEBUG] DEBUG: DYNECT put/post with path: /REST/CNAMERecord/rhcloud.com/redmine-qgong1.dev.rhcloud.com/ json data: {"rdata":{"cname":"ec2-23-21-17-108.compute-1.amazonaws.com"},"ttl":"60"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:30809)
>2013-03-25 05:03:49.915 [DEBUG] DEBUG: DYNECT Response: {"status": "success", "data": {"zone": "rhcloud.com", "ttl": 60, "fqdn": "redmine-qgong1.dev.rhcloud.com", "record_type": "CNAME", "rdata": {"cname": "ec2-23-21-17-108.compute-1.amazonaws.com."}, "record_id": 0}, "job_id": 303445488, "msgs": [{"INFO": "update: Record updated", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:30809)
>2013-03-25 05:03:49.916 [DEBUG] DEBUG: DYNECT Response data: {"zone"=>"rhcloud.com", "ttl"=>60, "fqdn"=>"redmine-qgong1.dev.rhcloud.com", "record_type"=>"CNAME", "rdata"=>{"cname"=>"ec2-23-21-17-108.compute-1.amazonaws.com."}, "record_id"=>0} (pid:30809)
>2013-03-25 05:03:49.916 [DEBUG] DEBUG: Dynect Response Time (dyn_put_post): 0.684542407s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:49.916 [DEBUG] DEBUG: DYNECT put/post with path: /REST/Zone/rhcloud.com/ json data: {"publish":"true"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:30809)
>2013-03-25 05:03:51.916 [DEBUG] DEBUG: DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "increment", "serial": 4872319, "zone": "rhcloud.com"}, "job_id": 303445489, "msgs": [{"INFO": "publish: rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:30809)
>2013-03-25 05:03:51.916 [DEBUG] DEBUG: DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"increment", "serial"=>4872319, "zone"=>"rhcloud.com"} (pid:30809)
>2013-03-25 05:03:51.917 [DEBUG] DEBUG: Dynect Response Time (dyn_put_post): 2.00049794s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:51.917 [DEBUG] DEBUG: DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:30809)
>2013-03-25 05:03:52.329 [DEBUG] DEBUG: DYNECT Response: {"status": "success", "data": {}, "job_id": 303445517, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:30809)
>2013-03-25 05:03:52.330 [DEBUG] DEBUG: DYNECT Response data: {} (pid:30809)
>2013-03-25 05:03:52.330 [DEBUG] DEBUG: Dynect Response Time (dyn_delete): 0.41311425s  (Request ID: ) (pid:30809)
>2013-03-25 05:03:52.333 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"add-alias", :args=>{"--with-app-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-app-name"=>"redmine", "--with-container-uuid"=>"b14b549494f611e28b4522000aa505b0", "--with-container-name"=>"redmine", "--with-namespace"=>"qgong1", "--with-uid"=>1004, "--with-request-id"=>nil, "--with-alias-name"=>#<Alias _id: 514fbeb5737a7d1575000213, _type: nil, fqdn: "bar.qgong.com", has_private_ssl_certificate: false, certificate_added_at: nil>, "--cart-name"=>"openshift-origin-node"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: ) (pid:30809)
>2013-03-25 05:05:02.595 [DEBUG] Dalli::Server#connect localhost:11212 (pid:1798)
>2013-03-25 05:05:02.605 [INFO ] localhost:11212 failed (count: 54) (pid:1798)
>2013-03-25 05:05:02.605 [DEBUG] localhost:11212 is still down (for 18668.971 seconds now) (pid:1798)
>2013-03-25 05:05:02.606 [INFO ] Started DELETE "/broker/rest/domains/qgong1/applications/jbosstestbldr" for 127.0.0.1 at 2013-03-25 05:05:02 -0400 (pid:1798)
>2013-03-25 05:05:02.609 [INFO ] Processing by ApplicationsController#destroy as JSON (pid:1798)
>2013-03-25 05:05:02.614 [INFO ] Parameters: {"domain_id"=>"qgong1", "id"=>"jbosstestbldr"} (pid:1798)
>2013-03-25 05:05:02.636 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (4.3736ms) (pid:1798)
>2013-03-25 05:05:02.641 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"login"=>"qgong@redhat.com"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (3.4425ms) (pid:1798)
>2013-03-25 05:05:02.643 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"514faf72737a7d1575000001"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (0.8810ms) (pid:1798)
>2013-03-25 05:05:02.676 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"domain_id"=>"514faf7f737a7d1575000005"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (32.8028ms) (pid:1798)
>2013-03-25 05:05:02.684 [DEBUG] SUCCESS ACTION=AUTHENTICATE USER_ID=514faf72737a7d1575000001 LOGIN=qgong@redhat.com IP=127.0.0.1 SCOPES=application/514fb3e7737a7d0a1e000001/scale application/514fb3e7737a7d0a1e000001/build Authenticated (pid:1798)
>2013-03-25 05:05:02.686 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"owner_id"=>"514faf72737a7d1575000001", "canonical_namespace"=>"qgong1"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.9296ms) (pid:1798)
>2013-03-25 05:05:02.687 [DEBUG] SUCCESS ACTION=DELETE_APPLICATION USER_ID=514faf72737a7d1575000001 LOGIN=qgong@redhat.com Found domain qgong1 (pid:1798)
>2013-03-25 05:05:02.688 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"domain_id"=>"514faf7f737a7d1575000005", "canonical_name"=>"jbosstestbldr"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (1.2107ms) (pid:1798)
>2013-03-25 05:05:02.694 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"514faf7f737a7d1575000005"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (4.0777ms) (pid:1798)
>2013-03-25 05:05:02.735 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"domain_id"=>"514faf7f737a7d1575000005"} flags=[:slave_ok] limit=0 skip=0 batch_size=nil fields=nil (37.3862ms) (pid:1798)
>2013-03-25 05:05:02.751 [DEBUG] down_retry_delay not reached for localhost:11212 (0.854 seconds left) (pid:1798)
>2013-03-25 05:05:02.757 [DEBUG] Removing feature jbossas-7 (pid:1798)
>2013-03-25 05:05:02.767 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514faf72737a7d1575000001", "$or"=>[{"app_ids.51500eaf737a7d41c8000138"=>{"$exists"=>false}}, {"app_ids.51500eaf737a7d41c8000138"=>{"$lt"=>1364202302}}]}, :new=>true, :update=>{"$set"=>{"app_ids.51500eaf737a7d41c8000138"=>1364202902}}} (4.4131ms) (pid:1798)
>2013-03-25 05:05:02.775 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$push"=>{"pending_op_groups"=>{"_id"=>"5150133e737a7d41c8000151", "num_gears_added"=>0, "num_gears_removed"=>0, "num_gears_created"=>0, "num_gears_destroyed"=>0, "num_gears_rolled_back"=>0, "user_agent"=>nil, "op_type"=>:remove_features, "args"=>{"features"=>["jbossas-7"], "group_overrides"=>[]}, "parent_op_id"=>nil, "updated_at"=>2013-03-25 09:05:02 UTC, "created_at"=>2013-03-25 09:05:02 UTC}}} flags=[] (pid:1798)
>2013-03-25 05:05:02.775 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (3.0334ms) (pid:1798)
>2013-03-25 05:05:02.777 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={:_id=>"51500eaf737a7d41c8000138"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.9141ms) (pid:1798)
>2013-03-25 05:05:02.790 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"514faf7f737a7d1575000005"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.6514ms) (pid:1798)
>2013-03-25 05:05:02.792 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"514faf72737a7d1575000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 batch_size=nil fields=nil (0.4408ms) (pid:1798)
>2013-03-25 05:05:02.804 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=locks selector={"$query"=>{"user_id"=>"514faf72737a7d1575000001"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (4.4093ms) (pid:1798)
>2013-03-25 05:05:02.810 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514faf72737a7d1575000001", "$or"=>[{"locked"=>false}, {"#<Origin::Key:0x000000065b84d8>"=>1364202302}], "app_ids.51500eaf737a7d41c8000138"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{:locked=>true, :timeout=>1364202902}}} (0.6154ms) (pid:1798)
>2013-03-25 05:05:02.811 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={:_id=>"514faf72737a7d1575000001"} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (0.4063ms) (pid:1798)
>2013-03-25 05:05:02.839 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$pushAll"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"5150133e737a7d41c8000158", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[]}}, {"_id"=>"5150133e737a7d41c8000152", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:destroy_gear, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}}, {"_id"=>"5150133e737a7d41c8000153", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:deregister_dns, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000152"]}, {"_id"=>"5150133e737a7d41c8000154", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:unreserve_uid, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000153"]}, {"_id"=>"5150133e737a7d41c8000155", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:delete_gear, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000154"]}, {"_id"=>"5150133e737a7d41c8000156", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"514faf72737a7d1575000001", "parent_user_id"=>nil, "app_name"=>"jbosstestbldr", "gear_ref"=>"51500eaf737a7d41c8000138", "event"=>"end", "usage_type"=>"GEAR_USAGE"}, "prereq"=>["5150133e737a7d41c8000155"]}, {"_id"=>"5150133e737a7d41c8000157", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:del_component, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "comp_spec"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}}, "prereq"=>["5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156"]}, {"_id"=>"5150133e737a7d41c8000159", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:destroy_group_instance, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146"}, "prereq"=>["5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156", "5150133e737a7d41c8000157"]}, {"_id"=>"5150133e737a7d41c800015a", "state"=>:init, "retry_count"=>0, "saved_values"=>{:connections=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["5150133e737a7d41c8000158", "5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156", "5150133e737a7d41c8000157", "5150133e737a7d41c8000159"]}, {"_id"=>"5150133e737a7d41c800015b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["5150133e737a7d41c800015a"]}]}} flags=[] (pid:1798)
>2013-03-25 05:05:02.839 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (6.1495ms) (pid:1798)
>2013-03-25 05:05:02.864 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$set"=>{"pending_op_groups.0.num_gears_removed"=>1, "pending_op_groups.0.updated_at"=>2013-03-25 09:05:02 UTC}} flags=[] (pid:1798)
>2013-03-25 05:05:02.864 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.3749ms) (pid:1798)
>2013-03-25 05:05:02.872 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"514faf72737a7d1575000001", "locked"=>true, "app_ids.51500eaf737a7d41c8000138"=>{"$exists"=>true}}, :new=>true, :update=>{"$set"=>{"locked"=>false}}} (0.7772ms) (pid:1798)
>2013-03-25 05:05:02.876 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"_id"=>"51500eaf737a7d41c8000138"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil (2.4917ms) (pid:1798)
>2013-03-25 05:05:02.906 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$set"=>{"pending_op_groups.0.pending_ops"=>[{"_id"=>"5150133e737a7d41c8000158", "state"=>:init, "retry_count"=>0, "saved_values"=>{"group_overrides"=>[{"components"=>[{"comp"=>"jbossas-7", "cart"=>"jbossas-7"}], "min_gears"=>1, "max_gears"=>1}]}, "op_type"=>:set_group_overrides, "args"=>{"group_overrides"=>[]}}, {"_id"=>"5150133e737a7d41c8000152", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:destroy_gear, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}}, {"_id"=>"5150133e737a7d41c8000153", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:deregister_dns, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000152"]}, {"_id"=>"5150133e737a7d41c8000154", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:unreserve_uid, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000153"]}, {"_id"=>"5150133e737a7d41c8000155", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:delete_gear, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "gear_id"=>"51500eaf737a7d41c8000138"}, "prereq"=>["5150133e737a7d41c8000154"]}, {"_id"=>"5150133e737a7d41c8000156", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:track_usage, "args"=>{"user_id"=>"514faf72737a7d1575000001", "parent_user_id"=>nil, "app_name"=>"jbosstestbldr", "gear_ref"=>"51500eaf737a7d41c8000138", "event"=>"end", "usage_type"=>"GEAR_USAGE"}, "prereq"=>["5150133e737a7d41c8000155"]}, {"_id"=>"5150133e737a7d41c8000157", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:del_component, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146", "comp_spec"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}}, "prereq"=>["5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156"]}, {"_id"=>"5150133e737a7d41c8000159", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:destroy_group_instance, "args"=>{"group_instance_id"=>"51500eaf737a7d41c8000146"}, "prereq"=>["5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156", "5150133e737a7d41c8000157"]}, {"_id"=>"5150133e737a7d41c800015a", "state"=>:init, "retry_count"=>0, "saved_values"=>{"connections"=>[{"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_cluster", "to_connector_name"=>"set_jboss_cluster", "connection_type"=>"NET_TCP:jboss-cluster-info"}, {"from_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "to_comp_inst"=>{"cart"=>"jbossas-7", "comp"=>"jbossas-7"}, "from_connector_name"=>"publish_jboss_remoting", "to_connector_name"=>"set_jboss_remoting", "connection_type"=>"NET_TCP:jboss-remoting-info"}]}, "op_type"=>:set_connections, "args"=>{"connections"=>[]}, "prereq"=>["5150133e737a7d41c8000158", "5150133e737a7d41c8000152", "5150133e737a7d41c8000153", "5150133e737a7d41c8000154", "5150133e737a7d41c8000155", "5150133e737a7d41c8000156", "5150133e737a7d41c8000157", "5150133e737a7d41c8000159"]}, {"_id"=>"5150133e737a7d41c800015b", "state"=>:init, "retry_count"=>0, "saved_values"=>[], "op_type"=>:execute_connections, "prereq"=>["5150133e737a7d41c800015a"]}]}} flags=[] (pid:1798)
>2013-03-25 05:05:02.907 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (2.9671ms) (pid:1798)
>2013-03-25 05:05:02.932 [DEBUG] Execute set_group_overrides (pid:1798)
>2013-03-25 05:05:02.958 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$set"=>{"group_overrides"=>[], "updated_at"=>2013-03-25 09:05:02 UTC}} flags=[] (pid:1798)
>2013-03-25 05:05:02.958 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.8249ms) (pid:1798)
>2013-03-25 05:05:02.962 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$set"=>{"pending_op_groups.0.pending_ops.0.state"=>:completed}} flags=[] (pid:1798)
>2013-03-25 05:05:02.963 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.6154ms) (pid:1798)
>2013-03-25 05:05:02.967 [DEBUG] Execute destroy_gear (pid:1798)
>2013-03-25 05:05:03.149 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"51500eaf737a7d0706000003", "--with-app-name"=>"jbosstestbldr", "--with-container-uuid"=>"51500eaf737a7d0706000003", "--with-container-name"=>"jbosstestbldr", "--with-namespace"=>"qgong1", "--with-uid"=>1001, "--with-request-id"=>"6c072f6f70c4ccb5733529f1e67575b4", "--cart-name"=>"openshift-origin-node"}}, ip-10-147-199-177, {'identity' => ip-10-147-199-177}) (Request ID: 6c072f6f70c4ccb5733529f1e67575b4) (pid:1798)
>2013-03-25 05:05:05.708 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x0000000531c798 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-147-199-177", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0}}>] (Request ID: 6c072f6f70c4ccb5733529f1e67575b4) (pid:1798)
>2013-03-25 05:05:05.716 [DEBUG] DEBUG: MCollective Response Time (execute_direct: app-destroy): 2.581555848s  (Request ID: 6c072f6f70c4ccb5733529f1e67575b4) (pid:1798)
>2013-03-25 05:05:05.838 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=districts selector={"uuid"=>"51500bbc737a7d0c7c000001", "available_uids"=>{"$nin"=>[1001]}} update={"$push"=>{"available_uids"=>1001}, "$inc"=>{"available_capacity"=>1}} flags=[] (pid:1798)
>2013-03-25 05:05:05.839 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (4.5352ms) (pid:1798)
>2013-03-25 05:05:05.841 [DEBUG] MOPED: 127.0.0.1:27017 UPDATE       database=openshift_broker_dev collection=applications selector={"_id"=>"51500eaf737a7d41c8000138"} update={"$set"=>{"pending_op_groups.0.pending_ops.1.state"=>:completed}} flags=[] (pid:1798)
>2013-03-25 05:05:05.841 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (1.4946ms) (pid:1798)
>2013-03-25 05:05:05.845 [DEBUG] MOPED: 127.0.0.1:27017 QUER

Actions: View

Attachments on bug 927181: 715942 | 717469