Bug 1023520 - Several exceptions reported from oo_update_cluster
Summary: Several exceptions reported from oo_update_cluster
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Online
Classification: Red Hat
Component: Containers
Version: 2.x
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: ---
Assignee: Andy Goldstein
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-10-25 15:32 UTC by Jessica Forrester
Modified: 2015-05-14 23:31 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-01-24 03:27:02 UTC
Target Upstream Version:

Attachments (Terms of Use)
Comment (68.18 KB, text/plain)
2013-10-25 19:48 UTC, Dan McPherson 		no flags Details
Comment (121.02 KB, text/plain)
2013-10-25 19:56 UTC, Dan McPherson 		no flags Details
Comment (121.02 KB, text/plain)
2013-10-25 19:56 UTC, Dan McPherson 		no flags Details
View All Add an attachment (proposed patch, testcase, etc.)

Description Jessica Forrester 2013-10-25 15:32:15 UTC 
Description of problem:
Several different exceptions are being reported on INT from MCollective::Agent::Openshift#update-cluster_openshift-origin-node

1)
NoMethodError: undefined method `join' for nil:NilClass
…e/model/application_container_ext/
cartridge_actions.rb:1246:in `update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1001:in `block in oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 302:in `with_container_from_args'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1000:in `oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 140:in `execute_action'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 105:in `cartridge_do_action'
…h/ruby193/root/usr/share/ruby/mcollective/rpc/
agent.rb:  86:in `handlemsg'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 126:in `block (2 levels) in dispatch'
         /opt/rh/ruby193/root/usr/share/ruby/
timeout.rb:  69:in `timeout'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 125:in `block in dispatch'



2)
NoMethodError: undefined method `each_value' for nil:NilClass
…e/model/application_container_ext/
cartridge_actions.rb:1135:in `generate_update_cluster_control_args'
…e/model/application_container_ext/
cartridge_actions.rb:1265:in `update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1001:in `block in oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 302:in `with_container_from_args'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1000:in `oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 140:in `execute_action'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 105:in `cartridge_do_action'
…h/ruby193/root/usr/share/ruby/mcollective/rpc/
agent.rb:  86:in `handlemsg'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 126:in `block (2 levels) in dispatch'
         /opt/rh/ruby193/root/usr/share/ruby/
timeout.rb:  69:in `timeout'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 125:in `block in dispatch'


3)
NoMethodError: undefined method `keys' for nil:NilClass
…e/model/application_container_ext/
cartridge_actions.rb:1219:in `block in update_cluster'
…e/model/application_container_ext/
cartridge_actions.rb:1218:in `select'
…e/model/application_container_ext/
cartridge_actions.rb:1218:in `update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1001:in `block in oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 302:in `with_container_from_args'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1000:in `oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 140:in `execute_action'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 105:in `cartridge_do_action'
…h/ruby193/root/usr/share/ruby/mcollective/rpc/
agent.rb:  86:in `handlemsg'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 126:in `block (2 levels) in dispatch'
         /opt/rh/ruby193/root/usr/share/ruby/
timeout.rb:  69:in `timeout'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 125:in `block in dispatch'


4)
TypeError: can't convert nil into String 
 …1.16.2/lib/openshift-origin-common/utils/
path_utils.rb:  76:in `join'
…1.16.2/lib/openshift-origin-common/utils/
path_utils.rb:  76:in `join'
…lib/openshift-origin-node/model/
deployment_metadata.rb:  45:in `initialize'
…in-node/model/application_container_ext/
deployments.rb:  12:in `new'
…in-node/model/application_container_ext/
deployments.rb:  12:in `deployment_metadata_for'
…e/model/application_container_ext/
cartridge_actions.rb:1236:in `update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1001:in `block in oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 302:in `with_container_from_args'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb:1000:in `oo_update_cluster'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 140:in `execute_action'
…usr/libexec/mcollective/mcollective/agent/
openshift.rb: 105:in `cartridge_do_action'
…h/ruby193/root/usr/share/ruby/mcollective/rpc/
agent.rb:  86:in `handlemsg'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 126:in `block (2 levels) in dispatch'
         /opt/rh/ruby193/root/usr/share/ruby/
timeout.rb:  69:in `timeout'
…t/rh/ruby193/root/usr/share/ruby/mcollective/
agents.rb: 125:in `block in dispatch'
Comment 1 Andy Goldstein 2013-10-25 15:59:53 UTC 
Jessica, could you please include more context around these exceptions or attach the logs for me to review? Thanks!

Also, did any of these errors apply to upgraded applications, or strictly new ones created after this code was deployed?
Comment 2 Dan McPherson 2013-10-25 17:54:27 UTC 
Example of 1)

I, [2013-10-25T07:49:57.192248 #19955]  INFO -- : openshift.rb:94:in `cartridge_do_action' cartridge_do_action validation = openshift-origin-node update-cluster {"--with-app-uuid"=>"5264ee526cec0e761f00006c", "--with-app-name"=>"scaledbs", "--with-container-uuid"=>"5264ee526cec0e761f00006c", "--with-container-name"=>"scaledbs", "--with-namespace"=>"wjiangint", "--with-uid"=>1454, "--with-request-id"=>"7483f644611a17f6b7c39613a63ff51c", "--proxy-gears"=>"5264ee526cec0e761f00006c,scaledbs,wjiangint,ex-std-node2.int.rhcloud.com", "--web-gears"=>"5264ee526cec0e761f00006c,scaledbs,wjiangint,ex-std-node2.int.rhcloud.com,40301 5264eeb56cec0e761f000091,5264eeb56cec0e761f000091,wjiangint,ex-std-node3.int.rhcloud.com,53741 526a5a9903ef64b8e0000003,526a5a9903ef64b8e0000003,wjiangint,ex-std-node1.int.rhcloud.com,50006", "--cart-name"=>"openshift-origin-node"}
I, [2013-10-25T07:49:57.193014 #19955]  INFO -- : openshift.rb:135:in `execute_action' Executing action [update-cluster] using method oo_update_cluster with args [{"--with-app-uuid"=>"5264ee526cec0e761f00006c", "--with-app-name"=>"scaledbs", "--with-container-uuid"=>"5264ee526cec0e761f00006c", "--with-container-name"=>"scaledbs", "--with-namespace"=>"wjiangint", "--with-uid"=>1454, "--with-request-id"=>"7483f644611a17f6b7c39613a63ff51c", "--proxy-gears"=>"5264ee526cec0e761f00006c,scaledbs,wjiangint,ex-std-node2.int.rhcloud.com", "--web-gears"=>"5264ee526cec0e761f00006c,scaledbs,wjiangint,ex-std-node2.int.rhcloud.com,40301 5264eeb56cec0e761f000091,5264eeb56cec0e761f000091,wjiangint,ex-std-node3.int.rhcloud.com,53741 526a5a9903ef64b8e0000003,526a5a9903ef64b8e0000003,wjiangint,ex-std-node1.int.rhcloud.com,50006", "--cart-name"=>"openshift-origin-node"}]
E, [2013-10-25T07:50:13.137419 #19955] ERROR -- : openshift.rb:313:in `rescue in with_container_from_args' undefined method `join' for nil:NilClass
E, [2013-10-25T07:50:13.137667 #19955] ERROR -- : openshift.rb:314:in `rescue in with_container_from_args' /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/cartridge_actions.rb:1246:in `update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1001:in `block in oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:302:in `with_container_from_args'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1000:in `oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:140:in `execute_action'
(eval):3:in `block in execute_action_with_newrelic_transaction_trace'
/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'
(eval):2:in `execute_action_with_newrelic_transaction_trace'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:105:in `cartridge_do_action'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/rpc/agent.rb:86:in `handlemsg'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:126:in `block (2 levels) in dispatch'
/opt/rh/ruby193/root/usr/share/ruby/timeout.rb:69:in `timeout'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:125:in `block in dispatch'
I, [2013-10-25T07:50:13.137837 #19955]  INFO -- : openshift.rb:151:in `execute_action' Finished executing action [update-cluster] (1)
I, [2013-10-25T07:50:13.217745 #19955]  INFO -- : openshift.rb:115:in `cartridge_do_action' cartridge_do_action failed (1)
------
undefined method `join' for nil:NilClass
------)
I, [2013-10-25T07:50:13.338804 #19955]  INFO -- : openshift.rb:93:in `cartridge_do_action' cartridge_do_action call / action: cartridge_do, agent=openshift, data={:cartridge=>"openshift-origin-node",
 :action=>"update-cluster",
 :args=>
  {"--with-app-uuid"=>"5264ee526cec0e761f00006c",
   "--with-app-name"=>"scaledbs",
   "--with-container-uuid"=>"5264ee526cec0e761f00006c",
   "--with-container-name"=>"scaledbs",
   "--with-namespace"=>"wjiangint",
   "--with-uid"=>1454,
   "--with-request-id"=>"7483f644611a17f6b7c39613a63ff51c",
   "--rollback"=>true,
   "--cart-name"=>"openshift-origin-node"},
 :process_results=>true}

I, [2013-10-25T07:50:13.339166 #19955]  INFO -- : openshift.rb:94:in `cartridge_do_action' cartridge_do_action validation = openshift-origin-node update-cluster {"--with-app-uuid"=>"5264ee526cec0e761f00006c", "--with-app-name"=>"scaledbs", "--with-container-uuid"=>"5264ee526cec0e761f00006c", "--with-container-name"=>"scaledbs", "--with-namespace"=>"wjiangint", "--with-uid"=>1454, "--with-request-id"=>"7483f644611a17f6b7c39613a63ff51c", "--rollback"=>true, "--cart-name"=>"openshift-origin-node"}
I, [2013-10-25T07:50:13.340389 #19955]  INFO -- : openshift.rb:135:in `execute_action' Executing action [update-cluster] using method oo_update_cluster with args [{"--with-app-uuid"=>"5264ee526cec0e761f00006c", "--with-app-name"=>"scaledbs", "--with-container-uuid"=>"5264ee526cec0e761f00006c", "--with-container-name"=>"scaledbs", "--with-namespace"=>"wjiangint", "--with-uid"=>1454, "--with-request-id"=>"7483f644611a17f6b7c39613a63ff51c", "--rollback"=>true, "--cart-name"=>"openshift-origin-node"}]
I, [2013-10-25T07:50:27.480584 #19955]  INFO -- : openshift.rb:151:in `execute_action' Finished executing action [update-cluster] (0)
I, [2013-10-25T07:50:27.600684 #19955]  INFO -- : openshift.rb:113:in `cartridge_do_action' cartridge_do_action reply (0):
------
Comment 3 Dan McPherson 2013-10-25 19:48:52 UTC 
Created attachment 915793 [details]
Comment

(This comment was longer than 65,535 characters and has been moved to an attachment by Red Hat Bugzilla).
Comment 4 Dan McPherson 2013-10-25 19:56:09 UTC 
Created attachment 915794 [details]
Comment

(This comment was longer than 65,535 characters and has been moved to an attachment by Red Hat Bugzilla).
Comment 5 Dan McPherson 2013-10-25 19:56:30 UTC 
Created attachment 915795 [details]
Comment

(This comment was longer than 65,535 characters and has been moved to an attachment by Red Hat Bugzilla).
Comment 6 Dan McPherson 2013-10-25 20:00:37 UTC 
mco for 3:

I, [2013-10-25T04:20:41.204529 #1967]  INFO -- : openshift.rb:93:in `cartridge_do_action' cartridge_do_action call / action: cartridge_do, agent=openshift, data={:cartridge=>"openshift-origin-node",
 :action=>"user-var-list",
 :args=>
  {"--with-app-uuid"=>"526a28f103ef641616000305",
   "--with-app-name"=>"zqrwjrzv",
--
   "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44",
   "--proxy-gears"=>
    "526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com",
   "--web-gears"=>
    "526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com,63291 526a34c003ef642f04000450,526a34c003ef642f04000450,jhou,ex-std-node3.int.rhcloud.com,54541",
   "--cart-name"=>"openshift-origin-node"},
 :process_results=>true}

I, [2013-10-25T05:09:05.349244 #1967]  INFO -- : openshift.rb:94:in `cartridge_do_action' cartridge_do_action validation = openshift-origin-node update-cluster {"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--proxy-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com", "--web-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com,63291 526a34c003ef642f04000450,526a34c003ef642f04000450,jhou,ex-std-node3.int.rhcloud.com,54541", "--cart-name"=>"openshift-origin-node"}
I, [2013-10-25T05:09:05.355037 #1967]  INFO -- : openshift.rb:135:in `execute_action' Executing action [update-cluster] using method oo_update_cluster with args [{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--proxy-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com", "--web-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com,63291 526a34c003ef642f04000450,526a34c003ef642f04000450,jhou,ex-std-node3.int.rhcloud.com,54541", "--cart-name"=>"openshift-origin-node"}]
E, [2013-10-25T05:09:05.471883 #1967] ERROR -- : openshift.rb:313:in `rescue in with_container_from_args' undefined method `keys' for nil:NilClass
E, [2013-10-25T05:09:05.472148 #1967] ERROR -- : openshift.rb:314:in `rescue in with_container_from_args' /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/cartridge_actions.rb:1219:in `block in update_cluster'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/cartridge_actions.rb:1218:in `select'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/cartridge_actions.rb:1218:in `update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1001:in `block in oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:302:in `with_container_from_args'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1000:in `oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:140:in `execute_action'
(eval):3:in `block in execute_action_with_newrelic_transaction_trace'
/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'
(eval):2:in `execute_action_with_newrelic_transaction_trace'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:105:in `cartridge_do_action'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/rpc/agent.rb:86:in `handlemsg'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:126:in `block (2 levels) in dispatch'
/opt/rh/ruby193/root/usr/share/ruby/timeout.rb:69:in `timeout'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:125:in `block in dispatch'
I, [2013-10-25T05:09:05.472359 #1967]  INFO -- : openshift.rb:151:in `execute_action' Finished executing action [update-cluster] (1)
I, [2013-10-25T05:09:05.794779 #1967]  INFO -- : openshift.rb:115:in `cartridge_do_action' cartridge_do_action failed (1)
------
undefined method `keys' for nil:NilClass
------)
I, [2013-10-25T05:09:06.069522 #1967]  INFO -- : openshift.rb:93:in `cartridge_do_action' cartridge_do_action call / action: cartridge_do, agent=openshift, data={:cartridge=>"openshift-origin-node",
 :action=>"update-cluster",
 :args=>
  {"--with-app-uuid"=>"526a34c003ef642f0400044b",
   "--with-app-name"=>"app1s",
   "--with-container-uuid"=>"526a34c003ef642f0400044b",
   "--with-container-name"=>"app1s",
   "--with-namespace"=>"jhou",
   "--with-uid"=>6052,




platform.log

October 25 05:09:04 INFO Created cartridge directory 526a35036cec0e52bd000628/haproxy
October 25 05:09:04 INFO Creating 2 private endpoints for 526a35036cec0e52bd000628/haproxy
October 25 05:09:04 INFO IPs already allocated for 8080 in gear 526a35036cec0e52bd000628: ["127.13.87.1"]
October 25 05:09:04 INFO Created private endpoint for cart haproxy in gear 526a35036cec0e52bd000628: [OPENSHIFT_HAPROXY_IP=127.13.87.2, OPENSHIFT_HAPROXY_PORT=8080]
October 25 05:09:04 INFO IPs already allocated for 8080 in gear 526a35036cec0e52bd000628: ["127.13.87.2", "127.13.87.1"]
October 25 05:09:04 INFO Created private endpoint for cart haproxy in gear 526a35036cec0e52bd000628: [OPENSHIFT_HAPROXY_STATUS_IP=127.13.87.3, OPENSHIFT_HAPROXY_STATUS_PORT=8080]
October 25 05:09:05 INFO Backing up 526a34c003ef642f0400044bgear registry
October 25 05:09:05 INFO Retrieving 526a34c003ef642f0400044b gear registry entries prior to this update
October 25 05:09:05 INFO Clearing 526a34c003ef642f0400044b gear registry
October 25 05:09:05 INFO Adding gear registry 526a34c003ef642f0400044b new web entry: {:type=>:web, :uuid=>"526a34c003ef642f0400044b", :namespace=>"jhou", :dns=>"app1s-jhou.int.rhcloud.com", :proxy_hostname=>"ex-std-node1.int.rhcloud.com", :proxy_port=>"63291"}
October 25 05:09:05 INFO Adding gear registry 526a34c003ef642f0400044b new web entry: {:type=>:web, :uuid=>"526a34c003ef642f04000450", :namespace=>"jhou", :dns=>"526a34c003ef642f04000450-jhou.int.rhcloud.com", :proxy_hostname=>"ex-std-node3.int.rhcloud.com", :proxy_port=>"54541"}
October 25 05:09:05 INFO Adding gear registry 526a34c003ef642f0400044b new proxy entry: {:type=>:proxy, :uuid=>"526a34c003ef642f0400044b", :namespace=>"jhou", :dns=>"app1s-jhou.int.rhcloud.com", :proxy_hostname=>"ex-std-node1.int.rhcloud.com", :proxy_port=>0}
October 25 05:09:05 INFO Saving gear registry 526a34c003ef642f0400044b
October 25 05:09:05 INFO Retrieving updated gear registry 526a34c003ef642f0400044b entries
October 25 05:09:05 INFO Shell command 'quota --always-resolve -w 526a34c003ef642f0400044b' ran. rc=0 out=Disk quotas for user 526a34c003ef642f0400044b (uid 6052): 
     Filesystem  blocks   quota   limit   grace   files   quota   limit   grace
/dev/mapper/EBSStore01-user_home01    2512       0 1048576             247       0   40000        

October 25 05:09:05 INFO Shell command '/usr/sbin/lsof -i @127.13.87.2:8080 -i @127.13.87.3:8080' ran. rc=1 out=
October 25 05:09:05 INFO Running setup for 526a35036cec0e52bd000628/haproxy
October 25 05:09:06 INFO Restoring 526a34c003ef642f0400044b gear registry from backup




platform-trace.log

Nothing


production.log

/SHKu4Q2wHh0QNuTSUW14hIOmCRWCQsgbBU+kDWtuOYNvuU/znLeO09+Xmb+tJrBFDUxos951OAYIetfBMMOe7djCwRb4AijbjJn++0y9kkApWKLiW6b81N7KXnSnu7GrvJZ8QcSEnnQm1Y69h3SofsEKQlSgURUgYxu8+0pWCy2d/MKk4a4qOjrgj4QUbtLJBnSuoKkKPH51Q/c68axkvaO4UiH2QJ2K+cccX990QdRdVKne5Ke8Cvda7qV8CPunnGHr1bbWEFxOPun1qcPvsJlGxBVoJon9B9/5XETorSTYjfJXouwR4TazBnIQ==", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"application-526a34c003ef642f04000450"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a34c003ef642f04000465"}, :gear=>"526a34c003ef642f0400044b", :job=>{:cartridge=>"openshift-origin-node", :action=>"authorized-ssh-key-add", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--with-ssh-key"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQDh43XWg7LERxupWx/Ym9hswfA6loRkpMi5JOfX5C49RW6M6JnpyF53u8/VFYYADN8YN+9wwUEPrUTi6LsZAheAfgw5nxc3VTqFaiHuwFP9oc8yPCgclm+vC0Fn3S2foAjHqO1+fRDYDztAciD0uBT+pWqMsMrqdTdpHvgc6U6tYdKRqKCwNjo4K2bueq3MUMOPdxJp1SvrVJK0I+BNhG4iSaGFt++2dYr2X389kQ+6MNYpJpOuqXC734wWm27CQLvYtWRr3QXfKSV3HnybdYZPc/ffV7xE6MLMkbznBnCgdM8b8AvB41xMz5OvnyGf8+tGDrtKN+qL2+pLBPgZbxoF", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"5260aa5403ef64cdce000029-default"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a34c003ef642f04000467"}, :gear=>"526a34c003ef642f0400044b", :job=>{:cartridge=>"openshift-origin-node", :action=>"broker-auth-key-add", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--with-iv"=>"V8b/FggAJclxK5mvhXbrkPmLXyX3cPjFyy0ivC1I9nEkjjWo41pjwNtr8xBl\nIH4Fsf7fyrWKY+0QDE7tQCpOfY5y+7QqeukyDkWLGADVg3ykJQxr5NrJo8XU\nh5nTGlFT76sG07Impu1jkargGokBgVX9cBXkH/zEUIkPU4K3ojc=\n", "--with-token"=>"f3BWaNpuAWZ8LnpD72BeVgFz3yADW1bX9FAaIBR4U2BZhYS04eU/MdGuiM4N\n4hbB/RtfI29pSFmoR2BdnyqgGHlhNIUAaPuMr+E19eTuujk=\n"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}], exitcode: 0, from: ex-std-node1.int.rhcloud.com  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:08:29.168 [DEBUG] DEBUG: MCollective Response Time (execute_parallel): 3.551375439s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:08:29.295 [INFO ] Started GET "/broker/rest/api.json" for 127.0.0.1 at 2013-10-25 05:08:29 -0400 (pid:17909)
2013-10-25 05:08:29.298 [INFO ] Processing by ApiController#show as JSON (pid:17909)
2013-10-25 05:08:29.298 [DEBUG] API version 1.6 (pid:17909)
2013-10-25 05:08:29.314 [DEBUG] Execute NewCompOp (pid:13479)
2013-10-25 05:08:29.519 [INFO ] Completed 200 OK in 221ms (Views: 208.2ms) (pid:17909)
2013-10-25 05:08:29.740 [DEBUG] Execute AddCompOp (pid:13479)
2013-10-25 05:08:29.758 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='526a34c003ef642f0400044b' action='configure' (pid:13479)
2013-10-25 05:08:29.804 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"haproxy-1.4", :action=>"configure", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"haproxy-1.4", "--component-name"=>"web_proxy", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, ex-std-node1.int.rhcloud.com, {'identity' => ex-std-node1.int.rhcloud.com}) (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:08:42.953 [INFO ] Started GET "/broker/rest/applications.json?include=cartridges" for 66.187.233.202 at 2013-10-25 05:08:42 -0400 (pid:17909)
--
2013-10-25 05:09:01.211 [INFO ] Completed 200 OK in 9ms (Views: 5.2ms) (pid:14861)
2013-10-25 05:09:01.351 [DEBUG] DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "day", "serial": 2013220218, "zone": "int.rhcloud.com"}, "job_id": 537084034, "msgs": [{"INFO": "publish: int.rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:2384)
2013-10-25 05:09:01.351 [DEBUG] DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"day", "serial"=>2013220218, "zone"=>"int.rhcloud.com"} (pid:2384)
2013-10-25 05:09:01.351 [DEBUG] Dynect Response Time (dyn_put_post): 0.74901478s  (Request ID: bd13f57552477e2baec2a51ff3609816) (pid:2384)
2013-10-25 05:09:01.351 [DEBUG] DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:2384)
2013-10-25 05:09:01.804 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537084042, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:2384)
2013-10-25 05:09:01.804 [DEBUG] DYNECT Response data: {} (pid:2384)
2013-10-25 05:09:01.804 [DEBUG] Dynect Response Time (dyn_delete): 0.452808958s  (Request ID: bd13f57552477e2baec2a51ff3609816) (pid:2384)
2013-10-25 05:09:01.866 [DEBUG] Rollback CreateGearOp (pid:2384)
2013-10-25 05:09:01.869 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"526a2de26cec0e5b35000313", "--with-app-name"=>"app1", "--with-container-uuid"=>"526a34dc03ef64c70c00013d", "--with-container-name"=>"526a34dc03ef64c70c00013d", "--with-namespace"=>"z4kf26x1m1", "--with-uid"=>2406, "--with-request-id"=>"bd13f57552477e2baec2a51ff3609816", "--cart-name"=>"openshift-origin-node"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: bd13f57552477e2baec2a51ff3609816) (pid:2384)
2013-10-25 05:09:03.869 [DEBUG] DEBUG: Output of parallel execute: [{:tag=>{"expose-ports"=>"526a34c003ef642f04000471", "op_id"=>"526a34c003ef642f04000469"}, :gear=>"526a34c003ef642f04000450", :job=>{:cartridge=>"openshift-origin-node", :action=>"expose-port", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f04000450", "--with-container-name"=>"526a34c003ef642f04000450", "--with-namespace"=>"jhou", "--with-uid"=>4302, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"perl-5.10", "--component-name"=>"1jhou-perl-5.10", "--with-software-version"=>"5.10", "--cartridge-vendor"=>"1jhou"}}, :result_stdout=>"NOTIFY_ENDPOINT_CREATE: {\"external_address\":\"54.205.207.58\",\"external_port\":54541,\"internal_address\":\"127.8.103.1\",\"internal_port\":8080,\"protocols\":[\"http\",\"ws\"],\"description\":null,\"type\":[\"web_framework\"],\"mappings\":[{\"frontend\":\"\",\"backend\":\"\"},{\"frontend\":\"/health\",\"backend\":\"\"}]}\n", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}], exitcode: 0, from: ex-std-node3.int.rhcloud.com  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:03.870 [DEBUG] DEBUG: Output of parallel execute: [{:tag=>{"expose-ports"=>"526a34c003ef642f04000471", "op_id"=>"526a34c003ef642f04000468"}, :gear=>"526a34c003ef642f0400044b", :job=>{:cartridge=>"openshift-origin-node", :action=>"expose-port", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"perl-5.10", "--component-name"=>"1jhou-perl-5.10", "--with-software-version"=>"5.10", "--cartridge-vendor"=>"1jhou"}}, :result_stdout=>"NOTIFY_ENDPOINT_CREATE: {\"external_address\":\"50.19.66.196\",\"external_port\":63291,\"internal_address\":\"127.11.210.1\",\"internal_port\":8080,\"protocols\":[\"http\",\"ws\"],\"description\":null,\"type\":[\"web_framework\"],\"mappings\":[{\"frontend\":\"\",\"backend\":\"\"},{\"frontend\":\"/health\",\"backend\":\"\"}]}\n", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"expose-ports"=>"526a350d03ef642f0400047c", "op_id"=>"526a34c003ef642f0400046a"}, :gear=>"526a34c003ef642f0400044b", :job=>{:cartridge=>"openshift-origin-node", :action=>"expose-port", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"haproxy-1.4", "--component-name"=>"web_proxy", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, :result_stdout=>"NOTIFY_ENDPOINT_CREATE: {\"external_address\":\"50.19.66.196\",\"external_port\":63292,\"internal_address\":\"127.11.210.2\",\"internal_port\":8080,\"protocols\":[\"http\",\"ws\"],\"description\":null,\"type\":[\"load_balancer\"],\"mappings\":[{\"frontend\":\"\",\"backend\":\"\"},{\"frontend\":\"/health\",\"backend\":\"/configuration/health\"}]}\n", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}], exitcode: 0, from: ex-std-node1.int.rhcloud.com  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:03.870 [DEBUG] DEBUG: MCollective Response Time (execute_parallel): 10.395876917s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:04.897 [DEBUG] Execute UpdateClusterOp (pid:13479)
2013-10-25 05:09:05.211 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"update-cluster", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--proxy-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com", "--web-gears"=>"526a34c003ef642f0400044b,app1s,jhou,ex-std-node1.int.rhcloud.com,63291 526a34c003ef642f04000450,526a34c003ef642f04000450,jhou,ex-std-node3.int.rhcloud.com,54541", "--cart-name"=>"openshift-origin-node"}}, ex-std-node1.int.rhcloud.com, {'identity' => ex-std-node1.int.rhcloud.com}) (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:05.807 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007f3a898 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node1.int.rhcloud.com", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 1. Output undefined method `keys' for nil:NilClass", :data=>{:time=>nil, :output=>"undefined method `keys' for nil:NilClass", :exitcode=>1, :addtl_params=>nil}}>] (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:05.808 [DEBUG] DEBUG: MCollective Response Time (execute_direct: update-cluster): 0.598168606s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:05.808 [DEBUG] DEBUG: server results: undefined method `keys' for nil:NilClass (pid:13479)
2013-10-25 05:09:05.808 [ERROR] Node execution failure (invalid exit code from node). (pid:13479)
2013-10-25 05:09:05.809 [ERROR] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:2718:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:1738:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:518:in `block in update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:268:in `trace_execution_scoped'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:513:in `update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/gear.rb:267:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1255:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/relations/proxy.rb:143:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_ops/update_cluster_op.rb:4:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:75:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1538:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:660:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1584:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:653:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:251:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/controllers/applications_controller.rb:147: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:481:in `block in _run__1936774781886859751__process_action__90401671728794907__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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/lib/openshift/controller/action_log.rb:80: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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__1936774781886859751__process_action__90401671728794907__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/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:38:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:37: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/newrelic_rpm-3.6.6.147/lib/new_relic/rack/error_collector.rb:43:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/agent_hooks.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/browser_monitoring.rb:16: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__4244122412704982935__call__3184952806216346838__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/request_handler.rb:97:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:521:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:13479)
2013-10-25 05:09:05.809 [ERROR] Node execution failure (invalid exit code from node). (pid:13479)
2013-10-25 05:09:05.809 [DEBUG] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:2718:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:1738:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:518:in `block in update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:268:in `trace_execution_scoped'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:513:in `update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/gear.rb:267:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1255:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/relations/proxy.rb:143:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_ops/update_cluster_op.rb:4:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:75:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1538:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:660:in `block in add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1584:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:653:in `add_features'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:251:in `create_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/controllers/applications_controller.rb:147: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:481:in `block in _run__1936774781886859751__process_action__90401671728794907__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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/lib/openshift/controller/action_log.rb:80: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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__1936774781886859751__process_action__90401671728794907__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/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:38:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:37: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/newrelic_rpm-3.6.6.147/lib/new_relic/rack/error_collector.rb:43:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/agent_hooks.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/browser_monitoring.rb:16: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__4244122412704982935__call__3184952806216346838__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/request_handler.rb:97:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:521:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:13479)
2013-10-25 05:09:05.864 [DEBUG] Rollback UpdateClusterOp (pid:13479)
2013-10-25 05:09:05.868 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"update-cluster", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f0400044b", "--with-container-name"=>"app1s", "--with-namespace"=>"jhou", "--with-uid"=>6052, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--rollback"=>true, "--cart-name"=>"openshift-origin-node"}}, ex-std-node1.int.rhcloud.com, {'identity' => ex-std-node1.int.rhcloud.com}) (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:06.592 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007c003f8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node1.int.rhcloud.com", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 1. Output undefined method `each_value' for nil:NilClass", :data=>{:time=>nil, :output=>"undefined method `each_value' for nil:NilClass", :exitcode=>1, :addtl_params=>nil}}>] (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
--
2013-10-25 05:09:17.108 [DEBUG] Execute SetGroupOverridesOp (pid:2384)
2013-10-25 05:09:17.134 [DEBUG] Execute RemoveCompOp (pid:2384)
2013-10-25 05:09:17.143 [DEBUG] DEBUG: Deconfiguring cartridge 'jenkins-client-1' in application 'app1' on node 'ex-std-node2.int.rhcloud.com' (pid:2384)
2013-10-25 05:09:17.143 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='526a2de26cec0e5b35000313' action='deconfigure' (pid:2384)
2013-10-25 05:09:17.188 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"jenkins-client-1", :action=>"deconfigure", :args=>{"--with-app-uuid"=>"526a2de26cec0e5b35000313", "--with-app-name"=>"app1", "--with-container-uuid"=>"526a2de26cec0e5b35000313", "--with-container-name"=>"app1", "--with-namespace"=>"z4kf26x1m1", "--with-uid"=>1848, "--with-request-id"=>"9cf3f00b36d462fc5cad4879655bc79f", "--cart-name"=>"jenkins-client-1", "--component-name"=>"jenkins-client-1", "--with-software-version"=>"1", "--cartridge-vendor"=>"redhat"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 9cf3f00b36d462fc5cad4879655bc79f) (pid:2384)
2013-10-25 05:09:17.496 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000008122ca0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node1.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:17.497 [DEBUG] DEBUG: MCollective Response Time (execute_direct: deconfigure): 4.362324054s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:17.533 [DEBUG] Rollback AddCompOp (pid:13479)
2013-10-25 05:09:17.534 [DEBUG] DEBUG: Deconfiguring cartridge '1jhou-perl-5.10' in application 'app1s' on node 'ex-std-node3.int.rhcloud.com' (pid:13479)
2013-10-25 05:09:17.535 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='526a34c003ef642f0400044b' action='deconfigure' (pid:13479)
2013-10-25 05:09:17.585 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"1jhou-perl-5.10", :action=>"deconfigure", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f04000450", "--with-container-name"=>"526a34c003ef642f04000450", "--with-namespace"=>"jhou", "--with-uid"=>4302, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"perl-5.10", "--component-name"=>"1jhou-perl-5.10", "--with-software-version"=>"5.10", "--cartridge-vendor"=>"1jhou"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:19.444 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007e28248 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node2.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"CLIENT_RESULT: \nCLIENT_RESULT: The corresponding job 'app1-build' in Jenkins has been disabled.\nCLIENT_RESULT: You can re-enable or delete as desired.\nCLIENT_RESULT: Job URL: https://j1-z4kf26x1m1.int.rhcloud.com/job/app1-build/\n", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 9cf3f00b36d462fc5cad4879655bc79f) (pid:2384)
2013-10-25 05:09:19.445 [DEBUG] DEBUG: MCollective Response Time (execute_direct: deconfigure): 2.261206611s  (Request ID: 9cf3f00b36d462fc5cad4879655bc79f) (pid:2384)
2013-10-25 05:09:19.477 [DEBUG] Execute DeleteCompOp (pid:2384)
2013-10-25 05:09:19.578 [DEBUG] Execute UnsubscribeConnectionsOp (pid:2384)
2013-10-25 05:09:19.586 [DEBUG] Running unsubscribe connections (pid:2384)
2013-10-25 05:09:19.608 [DEBUG] Execute UpdateClusterOp (pid:2384)
2013-10-25 05:09:20.129 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"update-cluster", :args=>{"--with-app-uuid"=>"526a2de26cec0e5b35000313", "--with-app-name"=>"app1", "--with-container-uuid"=>"526a2de26cec0e5b35000313", "--with-container-name"=>"app1", "--with-namespace"=>"z4kf26x1m1", "--with-uid"=>1848, "--with-request-id"=>"9cf3f00b36d462fc5cad4879655bc79f", "--proxy-gears"=>"526a2de26cec0e5b35000313,app1,z4kf26x1m1,ex-std-node2.int.rhcloud.com", "--web-gears"=>"526a2de26cec0e5b35000313,app1,z4kf26x1m1,ex-std-node2.int.rhcloud.com,42271", "--cart-name"=>"openshift-origin-node"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 9cf3f00b36d462fc5cad4879655bc79f) (pid:2384)
2013-10-25 05:09:20.558 [INFO ] Started POST "/broker/analytics" for 127.0.0.1 at 2013-10-25 05:09:20 -0400 (pid:14861)
2013-10-25 05:09:20.562 [INFO ] Processing by BrokerController#analytics_post as XML (pid:14861)
2013-10-25 05:09:20.562 [INFO ] Parameters: {"json_data"=>"{\"app_uuid\":\"526a33ff03ef64b32b00007c\",\"action\":\"push\"}"} (pid:14861)
--
2013-10-25 05:09:22.593 [DEBUG] Dynect Response Time (dyn_put_post): 0.693444421s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:22.594 [DEBUG] DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:13479)
2013-10-25 05:09:23.227 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537084303, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:13479)
2013-10-25 05:09:23.229 [DEBUG] DYNECT Response data: {} (pid:13479)
2013-10-25 05:09:23.230 [DEBUG] Dynect Response Time (dyn_delete): 0.429058689s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:23.447 [DEBUG] Rollback RegisterDnsOp (pid:13479)
2013-10-25 05:09:23.455 [DEBUG] DYNECT Login with path: /REST/Session/ (pid:13479)
2013-10-25 05:09:23.681 [DEBUG] DYNECT Response: {"status": "success", "data": {"token": "VqX1kM1KQbzEjN4XSdu+O917AnlJhYZSEMMZhF69M6HhtrcaDNYaZj2oGL+OHtMPNWDZYAdB1ORtgHAIWdJmjWQHLQpR0pH69ej7yA0INhzRtBP5cuQWYEmP6vFEuDFXic+FpgL+zKZxjXbtw/rQsGBp7ylfyij/", "version": "3.5.3"}, "job_id": 537084307, "msgs": [{"INFO": "login: Login successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:13479)
2013-10-25 05:09:23.681 [DEBUG] DYNECT Response data: {"token"=>"VqX1kM1KQbzEjN4XSdu+O917AnlJhYZSEMMZhF69M6HhtrcaDNYaZj2oGL+OHtMPNWDZYAdB1ORtgHAIWdJmjWQHLQpR0pH69ej7yA0INhzRtBP5cuQWYEmP6vFEuDFXic+FpgL+zKZxjXbtw/rQsGBp7ylfyij/", "version"=>"3.5.3"} (pid:13479)
2013-10-25 05:09:23.681 [DEBUG] Dynect Response Time (dyn_login): 0.636233823s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:23.682 [DEBUG] DYNECT delete with path: /REST/CNAMERecord/int.rhcloud.com/526a34c003ef642f04000450-jhou.int.rhcloud.com/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:13479)
2013-10-25 05:09:24.192 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537084310, "msgs": [{"INFO": "delete: 1 records deleted", "SOURCE": "API-B", "ERR_CD": null, "LVL": "INFO"}]} (pid:13479)
2013-10-25 05:09:24.192 [DEBUG] DYNECT Response data: {} (pid:13479)
2013-10-25 05:09:24.192 [DEBUG] Dynect Response Time (dyn_delete): 0.510643202s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:24.192 [DEBUG] DYNECT put/post with path: /REST/Zone/int.rhcloud.com/ json data: {"publish":"true"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:13479)
2013-10-25 05:09:24.866 [DEBUG] DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "day", "serial": 2013220222, "zone": "int.rhcloud.com"}, "job_id": 537084317, "msgs": [{"INFO": "publish: int.rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:13479)
2013-10-25 05:09:24.871 [DEBUG] DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"day", "serial"=>2013220222, "zone"=>"int.rhcloud.com"} (pid:13479)
2013-10-25 05:09:24.871 [DEBUG] Dynect Response Time (dyn_put_post): 0.678642599s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:24.871 [DEBUG] DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:13479)
2013-10-25 05:09:25.305 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537084322, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:13479)
2013-10-25 05:09:25.306 [DEBUG] DYNECT Response data: {} (pid:13479)
--
2013-10-25 05:09:42.748 [DEBUG] API version 1.5 (pid:13657)
2013-10-25 05:09:42.756 [INFO ] Filter chain halted as :authenticate_user! rendered or redirected (pid:13657)
2013-10-25 05:09:42.757 [INFO ] Completed 401 Unauthorized in 1ms (pid:13657)
2013-10-25 05:09:44.546 [INFO ] Started GET "/broker/rest/domain/tr0iyp/applications.json" for 209.132.181.86 at 2013-10-25 05:09:44 -0400 (pid:13657)
2013-10-25 05:09:44.550 [INFO ] Processing by ApplicationsController#index as JSON (pid:13657)
2013-10-25 05:09:44.550 [INFO ] Parameters: {"domain_id"=>"tr0iyp", "application"=>{}} (pid:13657)
2013-10-25 05:09:44.550 [DEBUG] API version 1.5 (pid:13657)
2013-10-25 05:09:44.611 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000005aa5ed8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node1.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:44.612 [DEBUG] DEBUG: MCollective Response Time (execute_direct: app-destroy): 19.225877188s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:44.633 [DEBUG] Rollback CreateGearOp (pid:13479)
2013-10-25 05:09:44.636 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"526a34c003ef642f0400044b", "--with-app-name"=>"app1s", "--with-container-uuid"=>"526a34c003ef642f04000450", "--with-container-name"=>"526a34c003ef642f04000450", "--with-namespace"=>"jhou", "--with-uid"=>4302, "--with-request-id"=>"c6d2f293509dd34a60e2c34a26acbf44", "--cart-name"=>"openshift-origin-node"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:44.708 [INFO ] Started GET "/broker/rest/api.json" for 127.0.0.1 at 2013-10-25 05:09:44 -0400 (pid:14861)
2013-10-25 05:09:44.710 [INFO ] Processing by ApiController#show as JSON (pid:14861)
2013-10-25 05:09:44.710 [DEBUG] API version 1.6 (pid:14861)
2013-10-25 05:09:44.800 [INFO ] Completed 200 OK in 90ms (Views: 85.6ms) (pid:14861)
2013-10-25 05:09:45.275 [DEBUG] Response from Streamline took (/wapps/streamline/login.html): 476.234153 ms (pid:13657)
2013-10-25 05:09:45.277 [DEBUG] POST Response code = 200 (pid:13657)
2013-10-25 05:09:45.278 [DEBUG] Current login = zhewang+2 / authenticated for zhewang+2 (pid:13657)
2013-10-25 05:09:45.350 [INFO ] Completed 200 OK in 485ms (Views: 0.5ms) (pid:13657)
2013-10-25 05:09:52.453 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007f31ae0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node3.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
2013-10-25 05:09:52.454 [DEBUG] DEBUG: MCollective Response Time (execute_direct: app-destroy): 7.820184301s  (Request ID: c6d2f293509dd34a60e2c34a26acbf44) (pid:13479)
Comment 7 Dan McPherson 2013-10-25 20:10:40 UTC 
mco from problem 4):

I, [2013-10-25T07:47:21.637404 #21180]  INFO -- : openshift.rb:94:in `cartridge_do_action' cartridge_do_action validation = openshift-origin-node update-cluster {"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"5260d86303ef642f2b000236", "--with-container-name"=>"py33spsql", "--with-namespace"=>"wjiangint", "--with-uid"=>3415, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--proxy-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com", "--web-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com,50106 5260d8d803ef642f2b000279,5260d8d803ef642f2b000279,wjiangint,ex-std-node1.int.rhcloud.com,47251 526a5a0403ef64b8a70001b5,526a5a0403ef64b8a70001b5,wjiangint,ex-std-node2.int.rhcloud.com,41801", "--cart-name"=>"openshift-origin-node"}
I, [2013-10-25T07:47:21.638810 #21180]  INFO -- : openshift.rb:135:in `execute_action' Executing action [update-cluster] using method oo_update_cluster with args [{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"5260d86303ef642f2b000236", "--with-container-name"=>"py33spsql", "--with-namespace"=>"wjiangint", "--with-uid"=>3415, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--proxy-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com", "--web-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com,50106 5260d8d803ef642f2b000279,5260d8d803ef642f2b000279,wjiangint,ex-std-node1.int.rhcloud.com,47251 526a5a0403ef64b8a70001b5,526a5a0403ef64b8a70001b5,wjiangint,ex-std-node2.int.rhcloud.com,41801", "--cart-name"=>"openshift-origin-node"}]
E, [2013-10-25T07:47:22.800609 #21180] ERROR -- : openshift.rb:313:in `rescue in with_container_from_args' can't convert nil into String
E, [2013-10-25T07:47:22.800860 #21180] ERROR -- : openshift.rb:314:in `rescue in with_container_from_args' /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-common-1.16.2/lib/openshift-origin-common/utils/path_utils.rb:76:in `join'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-common-1.16.2/lib/openshift-origin-common/utils/path_utils.rb:76:in `join'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/deployment_metadata.rb:45:in `initialize'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/deployments.rb:12:in `new'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/deployments.rb:12:in `deployment_metadata_for'
/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.16.5/lib/openshift-origin-node/model/application_container_ext/cartridge_actions.rb:1236:in `update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1001:in `block in oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:302:in `with_container_from_args'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:1000:in `oo_update_cluster'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:140:in `execute_action'
--
/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'
(eval):2:in `execute_action_with_newrelic_transaction_trace'
/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:105:in `cartridge_do_action'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/rpc/agent.rb:86:in `handlemsg'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:126:in `block (2 levels) in dispatch'
/opt/rh/ruby193/root/usr/share/ruby/timeout.rb:69:in `timeout'
/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:125:in `block in dispatch'
I, [2013-10-25T07:47:22.801100 #21180]  INFO -- : openshift.rb:151:in `execute_action' Finished executing action [update-cluster] (1)
I, [2013-10-25T07:47:22.882359 #21180]  INFO -- : openshift.rb:115:in `cartridge_do_action' cartridge_do_action failed (1)
------
can't convert nil into String
------)
I, [2013-10-25T07:47:23.015068 #21180]  INFO -- : openshift.rb:93:in `cartridge_do_action' cartridge_do_action call / action: cartridge_do, agent=openshift, data={:cartridge=>"openshift-origin-node",
 :action=>"update-cluster",
 :args=>
  {"--with-app-uuid"=>"5260d86303ef642f2b000236",
   "--with-app-name"=>"py33spsql",
   "--with-container-uuid"=>"5260d86303ef642f2b000236",
   "--with-container-name"=>"py33spsql",
   "--with-namespace"=>"wjiangint",
   "--with-uid"=>3415,




platform.log


October 25 07:47:13 INFO Unidling gear 5260d86303ef642f2b000236... [ OK ]
October 25 07:47:18 INFO Shell command 'quota --always-resolve -w 5260d86303ef642f2b000236' ran. rc=0 out=Disk quotas for user 5260d86303ef642f2b000236 (uid 3415): 
     Filesystem  blocks   quota   limit   grace   files   quota   limit   grace
/dev/mapper/EBSStore01-user_home01  290392       0 1048576            5632       0   40000        

October 25 07:47:21 INFO Backing up 5260d86303ef642f2b000236gear registry
October 25 07:47:21 INFO Retrieving 5260d86303ef642f2b000236 gear registry entries prior to this update
October 25 07:47:21 INFO Clearing 5260d86303ef642f2b000236 gear registry
October 25 07:47:21 INFO Adding gear registry 5260d86303ef642f2b000236 new web entry: {:type=>:web, :uuid=>"5260d86303ef642f2b000236", :namespace=>"wjiangint", :dns=>"py33spsql-wjiangint.int.rhcloud.com", :proxy_hostname=>"ex-std-node3.int.rhcloud.com", :proxy_port=>"50106"}
October 25 07:47:21 INFO Adding gear registry 5260d86303ef642f2b000236 new web entry: {:type=>:web, :uuid=>"5260d8d803ef642f2b000279", :namespace=>"wjiangint", :dns=>"5260d8d803ef642f2b000279-wjiangint.int.rhcloud.com", :proxy_hostname=>"ex-std-node1.int.rhcloud.com", :proxy_port=>"47251"}
October 25 07:47:21 INFO Adding gear registry 5260d86303ef642f2b000236 new web entry: {:type=>:web, :uuid=>"526a5a0403ef64b8a70001b5", :namespace=>"wjiangint", :dns=>"526a5a0403ef64b8a70001b5-wjiangint.int.rhcloud.com", :proxy_hostname=>"ex-std-node2.int.rhcloud.com", :proxy_port=>"41801"}
October 25 07:47:21 INFO Adding gear registry 5260d86303ef642f2b000236 new proxy entry: {:type=>:proxy, :uuid=>"5260d86303ef642f2b000236", :namespace=>"wjiangint", :dns=>"py33spsql-wjiangint.int.rhcloud.com", :proxy_hostname=>"ex-std-node3.int.rhcloud.com", :proxy_port=>0}
October 25 07:47:21 INFO Saving gear registry 5260d86303ef642f2b000236
October 25 07:47:21 INFO Retrieving updated gear registry 5260d86303ef642f2b000236 entries
October 25 07:47:22 INFO Shell command '/sbin/runuser -s /bin/sh 5260d86303ef642f2b000236 -c "exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c3,c352' /bin/sh -c \"rsync -avz --delete --rsh=/usr/bin/oo-ssh app-deployments/ 526a5a0403ef64b8a70001b5.rhcloud.com:app-deployments/\""' ran. rc=0 out=sending incremental file list
./
deleting 2013-10-25_07-46-16.910/repo/
deleting 2013-10-25_07-46-16.910/dependencies/
deleting 2013-10-25_07-46-16.910/build-dependencies/
deleting 2013-10-25_07-46-16.910/
current -> 2013-10-24_19-28-04.805
2013-10-25_04-07-19.252/
2013-10-25_04-07-19.252/metadata.json
2013-10-25_04-07-19.252/build-dependencies/
2013-10-25_04-07-19.252/dependencies/





platform-trace.log


October 25 07:45:53 INFO oo_spawn buffer(11/) Disk quotas for user 526a592103ef64b8a7000162 (uid 6988): 
     Filesystem  blocks   quota   limit   grace   files   quota   limit   grace
/dev/mapper/EBSStore01-user_home01    2096       0 1048576             360       0   40000        

October 25 07:47:13 INFO oo_spawn running /usr/sbin/httxt2dbm -f DB -i /etc/httpd/conf.d/openshift/idler.txt -o /etc/httpd/conf.d/openshift/idler.db-20131025-31405-lxxj66/new.db: {:unsetenv_others=>false, :close_others=>true, :in=>"/dev/null", :out=>#<IO:fd 12>, :err=>#<IO:fd 10>}
October 25 07:47:18 INFO oo_spawn running quota --always-resolve -w 5260d86303ef642f2b000236: {:unsetenv_others=>false, :close_others=>true, :in=>"/dev/null", :out=>#<IO:fd 12>, :err=>#<IO:fd 8>}
October 25 07:47:18 INFO oo_spawn buffer(11/) Disk quotas for user 5260d86303ef642f2b000236 (uid 3415): 
     Filesystem  blocks   quota   limit   grace   files   quota   limit   grace
/dev/mapper/EBSStore01-user_home01  290392       0 1048576            5632       0   40000        

October 25 07:47:21 INFO oo_spawn running /sbin/runuser -s /bin/sh 5260d86303ef642f2b000236 -c "exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c3,c352' /bin/sh -c \"rsync -avz --delete --rsh=/usr/bin/oo-ssh app-deployments/ 526a5a0403ef64b8a70001b5.rhcloud.com:app-deployments/\"": {:unsetenv_others=>true, :close_others=>true, :in=>"/dev/null", :chdir=>"/var/lib/openshift/5260d86303ef642f2b000236/", :out=>#<IO:fd 12>, :err=>#<IO:fd 8>}
October 25 07:47:22 INFO oo_spawn buffer(11/) sending incremental file list

October 25 07:47:22 INFO oo_spawn buffer(11/) ./

October 25 07:47:22 INFO oo_spawn buffer(11/) deleting 2013-10-25_07-46-16.910/repo/

October 25 07:47:22 INFO oo_spawn buffer(11/) deleting 2013-10-25_07-46-16.910/dependencies/

October 25 07:47:22 INFO oo_spawn buffer(11/) deleting 2013-10-25_07-46-16.910/build-dependencies/






production.log


sult_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"authorized-ssh-key-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-ssh-key"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQC7aEfCQQhFja2rEMEdNt2SSF5dcPOQPd9g61e6AuDQtI/t687TL0HsUcD+7G/VFmB5PyMbogflR19KupHno2t2/Q/zd7Nv9q+5BXeMXKJGr8IaINU1MIjyd4EWOU32mmosv9z87oQDvY1u2s15I01pBqWmv2r/DeZEKDlbLQbQ2Jckinh3Ufs7Lj7HFGPUi5DaujTg5x5IYAfyezSuIhbBZ3C0Ol59O+vsXQSkb23AKDVs+J/Ep60vwAUz1MVPFKykayOrAa23NeoVYkEuiwvH4BLLQrZYatyl2zXs85B3ivAjIJ02WB26fsVNnb9hMyZopMY9kGl87JaY3MC/Y36f", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"5260af1503ef64cdce000081-default"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"authorized-ssh-key-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-ssh-key"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQDBKBQzetMqif3kYcabnckEhd/RBD/Kk5MZUUBRRx5OjvCedUh1GuJM4eI1aKiD5QxUp0NCXUFORmaF5DpcC8A67bjvxibZUEMunEUps4cR26Axzox3bxq3qrzvk2jk2kMxTBe1u7gocwgtbQJw4oXgFWZid8bvIkgyZpgkXFVWWivbPjYV2O+IrLpsIMtynV3UAI0ep3fZp6vmGLaUeSexp9MFWE+4cu83lbM6Fjt3kFPPNn0znWxkfF69tELYxMPUePysjkUWaCQc5/HEPaHqQidAxDSAZyKBka66s0kMcC6Ox8YH+gFtl3LBq8I4foKP3ocFmTEIIoMyv8XADVQ/", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"5260af1503ef64cdce000081-asdfasdf"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"authorized-ssh-key-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-ssh-key"=>"AAAAB3NzaC1yc2EAAAABIwAAAQEAylY7pk0ajJ7ur084RpMgjlQEHkAYGrIKrnoiU7k1ShhZTUR/+nL/yBKYH0ikAn98jEKlvDjD9FilMhoo3WnWL9XYyGL2FxfRB2ly+W9602Lpa5YBkSZiiZTKiXFNRx3k/L2kUeoCWi1Q+vdzLntpHyXdJfyFHIxrwA6y3j3vqB+g2iBIj6LQ90gC5sZMhVPmn5fPRGFHN+Y5uwR+0p/gwsRLOmTsOCeWx/HEKq8+x4wGGfbOrs2g0ewXwrWjXvSXmvkiAnpbmWWanvpN4H62caZqXFnygsCpm1ZjhRZBRV4UT5sVFvRIwSKUddNmpBpywepvyb8mweuELXFlsnN53w==", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"5260af1503ef64cdce000081-adfasdf"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"authorized-ssh-key-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-ssh-key"=>"AAAAB3NzaC1yc2EAAAADAQABAAABAQCrBtLOUQfCo4x/DU0F3nb/3CEPMFo3mjBMn1trKcAQJjqHsPWFmiFrwjnkaxizlblsJysHIjSQqGkfLGvMFRb9ZUGCAfKWKUfBGjEMBsEYYegJUv1+cKRuwMq9VZo/TbzBiIU90uBo1J5uuuOJGYsMWaLYWs78QBNKtWnGP0tvv+YuAta5qiGN25vhpPtwwELqsgFpc7yf57Ly98tBoUcEpZloyCO0ryJxG5IV8krsQLeULGdbprOjFL6utZnT68bjg1AxplsLEDSCxdlcdUTBrTCIqobm/gLP2AHKTW0zEkMHQ2tBN6Z11rW7ycBLc63U0ILD+/bmu623/7Fuy3DN", "--with-ssh-key-type"=>"ssh-rsa", "--with-ssh-key-comment"=>"5260af1503ef64cdce000081-y"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"env-var-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-key"=>"JENKINS_URL", "--with-value"=>"https://jenkins-wjiangint.int.rhcloud.com/"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"env-var-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-key"=>"JENKINS_USERNAME", "--with-value"=>"system_builder"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"op_id"=>"526a5a0403ef64b8a70001ba"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"env-var-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-key"=>"JENKINS_PASSWORD", "--with-value"=>"bhrlSqTE9Ejy"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}], exitcode: 0, from: ex-std-node2.int.rhcloud.com  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:17.946 [DEBUG] DEBUG: MCollective Response Time (execute_parallel): 4.075440272s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:18.441 [DEBUG] Execute PatchUserEnvVarsOp (pid:19354)
2013-10-25 07:47:18.187 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"user-var-add", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"5260d86303ef642f2b000236", "--with-container-name"=>"py33spsql", "--with-namespace"=>"wjiangint", "--with-uid"=>3415, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--with-gears"=>"5260d86303ef642f2b00023a.rhcloud.com;5260d8d803ef642f2b000279.rhcloud.com;526a5a0403ef64b8a70001b5.rhcloud.com", "--cart-name"=>"openshift-origin-node"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:18.147 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007cc90f0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node3.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:18.147 [DEBUG] DEBUG: MCollective Response Time (execute_direct: user-var-add): 0.130771425s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:18.157 [DEBUG] Execute PostConfigureCompOp (pid:19354)
2013-10-25 07:47:18.171 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='5260d86303ef642f2b000236' action='post-configure' (pid:19354)
2013-10-25 07:47:18.280 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"cron-1.4", :action=>"post-configure", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"cron-1.4", "--component-name"=>"cron-1.4", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:19.180 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007e3ac18 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node2.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"Starting Cron cartridge\n", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:19.184 [DEBUG] DEBUG: MCollective Response Time (execute_direct: post-configure): 0.906815258s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:19.239 [DEBUG] Execute ExposePortOp (pid:19354)
2013-10-25 07:47:19.254 [DEBUG] Execute ExposePortOp (pid:19354)
2013-10-25 07:47:19.268 [DEBUG] Execute ExposePortOp (pid:19354)
2013-10-25 07:47:20.895 [DEBUG] DEBUG: Output of parallel execute: [{:tag=>{"expose-ports"=>"5260d89303ef642f2b000269", "op_id"=>"526a5a0403ef64b8a70001c1"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"expose-port", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"python-3.3", "--component-name"=>"python-3.3", "--with-software-version"=>"3.3", "--cartridge-vendor"=>"redhat"}}, :result_stdout=>"NOTIFY_ENDPOINT_CREATE: {\"external_address\":\"23.20.252.31\",\"external_port\":41801,\"internal_address\":\"127.3.109.1\",\"internal_port\":8080,\"protocols\":[\"http\",\"ws\"],\"description\":null,\"type\":[\"web_framework\"],\"mappings\":[{\"frontend\":\"\",\"backend\":\"\"},{\"frontend\":\"/health\",\"backend\":\"\"}]}\n", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}, {:tag=>{"expose-ports"=>"5260d8ba03ef642f2b00026d", "op_id"=>"526a5a0403ef64b8a70001c3"}, :gear=>"526a5a0403ef64b8a70001b5", :job=>{:cartridge=>"openshift-origin-node", :action=>"expose-port", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"cron-1.4", "--component-name"=>"cron-1.4", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, :result_stdout=>"", :result_stderr=>"", :result_exit_code=>0, :result_addtl_params=>nil}], exitcode: 0, from: ex-std-node2.int.rhcloud.com  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:20.896 [DEBUG] DEBUG: MCollective Response Time (execute_parallel): 1.614481128s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:21.151 [DEBUG] Execute UpdateClusterOp (pid:19354)
2013-10-25 07:47:21.461 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"update-cluster", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"5260d86303ef642f2b000236", "--with-container-name"=>"py33spsql", "--with-namespace"=>"wjiangint", "--with-uid"=>3415, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--proxy-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com", "--web-gears"=>"5260d86303ef642f2b000236,py33spsql,wjiangint,ex-std-node3.int.rhcloud.com,50106 5260d8d803ef642f2b000279,5260d8d803ef642f2b000279,wjiangint,ex-std-node1.int.rhcloud.com,47251 526a5a0403ef64b8a70001b5,526a5a0403ef64b8a70001b5,wjiangint,ex-std-node2.int.rhcloud.com,41801", "--cart-name"=>"openshift-origin-node"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:22.886 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000070f7df8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node3.int.rhcloud.com", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 1. Output can't convert nil into String", :data=>{:time=>nil, :output=>"can't convert nil into String", :exitcode=>1, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:22.887 [DEBUG] DEBUG: MCollective Response Time (execute_direct: update-cluster): 1.426768987s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:22.887 [DEBUG] DEBUG: server results: can't convert nil into String (pid:19354)
2013-10-25 07:47:22.888 [ERROR] Node execution failure (invalid exit code from node). (pid:19354)
2013-10-25 07:47:22.888 [ERROR] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:2718:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:1738:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:518:in `block in update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:268:in `trace_execution_scoped'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:513:in `update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/gear.rb:267:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1255:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/relations/proxy.rb:143:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_ops/update_cluster_op.rb:4:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:75:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1538:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:851:in `block in update_component_limits'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1584:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:845:in `update_component_limits'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/controllers/emb_cart_controller.rb:256:in `update'", "/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:481:in `block in _run__4315015283972704585__process_action__4302899414145919272__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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/lib/openshift/controller/action_log.rb:80: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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__4315015283972704585__process_action__4302899414145919272__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/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:38:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:37: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/newrelic_rpm-3.6.6.147/lib/new_relic/rack/error_collector.rb:43:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/agent_hooks.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/browser_monitoring.rb:16: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__4244122412704982935__call__3184952806216346838__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/request_handler.rb:97:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:521:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:19354)
2013-10-25 07:47:22.888 [ERROR] Node execution failure (invalid exit code from node). (pid:19354)
2013-10-25 07:47:22.889 [DEBUG] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:2718:in `parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:1738:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:518:in `block in update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:268:in `trace_execution_scoped'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:513:in `update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/gear.rb:267:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1255:in `update_cluster'", "/opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/relations/proxy.rb:143:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_ops/update_cluster_op.rb:4:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:75:in `block in execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `each'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/pending_app_op_group.rb:64:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1538:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:851:in `block in update_component_limits'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:1584:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/models/application.rb:845:in `update_component_limits'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/app/controllers/emb_cart_controller.rb:256:in `update'", "/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:481:in `block in _run__4315015283972704585__process_action__4302899414145919272__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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.4/lib/openshift/controller/action_log.rb:80: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_428'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__4315015283972704585__process_action__4302899414145919272__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/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:38:in `block in process_action'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:318:in `perform_action_with_newrelic_trace'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:37: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/newrelic_rpm-3.6.6.147/lib/new_relic/rack/error_collector.rb:43:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/agent_hooks.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/rack/browser_monitoring.rb:16: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__4244122412704982935__call__3184952806216346838__callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'", "/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'", "/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/request_handler.rb:97:in `process_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:521:in `accept_and_process_next_request'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/utils.rb:470:in `safe_fork'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'", "/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/passenger-spawn-server:102:in `<main>'"] (pid:19354)
2013-10-25 07:47:22.923 [DEBUG] Rollback UpdateClusterOp (pid:19354)
2013-10-25 07:47:22.928 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"update-cluster", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"5260d86303ef642f2b000236", "--with-container-name"=>"py33spsql", "--with-namespace"=>"wjiangint", "--with-uid"=>3415, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--rollback"=>true, "--cart-name"=>"openshift-origin-node"}}, ex-std-node3.int.rhcloud.com, {'identity' => ex-std-node3.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:27.325 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007bead50 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node3.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:27.326 [DEBUG] DEBUG: MCollective Response Time (execute_direct: update-cluster): 4.399169179s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:27.372 [DEBUG] Rollback SetGroupOverridesOp (pid:19354)
2013-10-25 07:47:27.393 [DEBUG] Rollback TrackUsageOp (pid:19354)
2013-10-25 07:47:27.410 [DEBUG] Rollback PatchUserEnvVarsOp (pid:19354)
2013-10-25 07:47:27.480 [DEBUG] Rollback AddCompOp (pid:19354)
2013-10-25 07:47:27.482 [DEBUG] DEBUG: Deconfiguring cartridge 'python-3.3' in application 'py33spsql' on node 'ex-std-node2.int.rhcloud.com' (pid:19354)
2013-10-25 07:47:27.482 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='5260d86303ef642f2b000236' action='deconfigure' (pid:19354)
2013-10-25 07:47:27.531 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"python-3.3", :action=>"deconfigure", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"python-3.3", "--component-name"=>"python-3.3", "--with-software-version"=>"3.3", "--cartridge-vendor"=>"redhat"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.271 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000083399d0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node2.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.272 [DEBUG] DEBUG: MCollective Response Time (execute_direct: deconfigure): 2.743891929s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Rollback ExposePortOp (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Parallel rollback not implemented: ExposePortOp (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Rollback ExposePortOp (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Parallel rollback not implemented: ExposePortOp (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Rollback ExposePortOp (pid:19354)
2013-10-25 07:47:30.288 [DEBUG] Parallel rollback not implemented: ExposePortOp (pid:19354)
2013-10-25 07:47:30.552 [DEBUG] Rollback UpdateAppConfigOp (pid:19354)
2013-10-25 07:47:30.553 [DEBUG] Parallel rollback not implemented: UpdateAppConfigOp (pid:19354)
2013-10-25 07:47:30.553 [DEBUG] Rollback PostConfigureCompOp (pid:19354)
2013-10-25 07:47:30.553 [DEBUG] Rollback not implemented: PostConfigureCompOp (pid:19354)
2013-10-25 07:47:30.615 [DEBUG] Rollback AddCompOp (pid:19354)
2013-10-25 07:47:30.617 [DEBUG] DEBUG: Deconfiguring cartridge 'cron-1.4' in application 'py33spsql' on node 'ex-std-node2.int.rhcloud.com' (pid:19354)
2013-10-25 07:47:30.617 [DEBUG] DEBUG: Sending to Nurture:application: app_uuid='5260d86303ef642f2b000236' action='deconfigure' (pid:19354)
2013-10-25 07:47:30.687 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"cron-1.4", :action=>"deconfigure", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"cron-1.4", "--component-name"=>"cron-1.4", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.907 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007d05730 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node2.int.rhcloud.com", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 1. Output Cartridge manifest not found: /var/lib/openshift/526a5a0403ef64b8a70001b5/python/metadata/manifest.yml missing", :data=>{:time=>nil, :output=>"Cartridge manifest not found: /var/lib/openshift/526a5a0403ef64b8a70001b5/python/metadata/manifest.yml missing", :exitcode=>1, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.908 [DEBUG] DEBUG: MCollective Response Time (execute_direct: deconfigure): 0.238117446s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:30.909 [DEBUG] DEBUG: server results: Cartridge manifest not found: /var/lib/openshift/526a5a0403ef64b8a70001b5/python/metadata/manifest.yml missing (pid:19354)
2013-10-25 07:47:30.911 [DEBUG] DEBUG: rpc_exec: Filtering rpc_exec to servers ["ex-std-node2.int.rhcloud.com"] (pid:19354)
2013-10-25 07:47:30.920 [DEBUG] DEBUG: rpc_exec: rpc_client=#<MCollective::RPC::Client:0x00000007d635b0> (pid:19354)
2013-10-25 07:47:30.991 [INFO ] Started GET "/broker/rest/api.json" for 127.0.0.1 at 2013-10-25 07:47:30 -0400 (pid:28209)
2013-10-25 07:47:30.992 [INFO ] Processing by ApiController#show as JSON (pid:28209)
2013-10-25 07:47:30.993 [DEBUG] API version 1.6 (pid:28209)
2013-10-25 07:47:31.276 [INFO ] Completed 200 OK in 10ms (Views: 5.4ms) (pid:28209)
2013-10-25 07:47:31.841 [DEBUG] DEBUG: Cartridge 'cron-1.4' not found on within application 'py33spsql/526a5a0403ef64b8a70001b5'.  Continuing with deconfigure. (pid:19354)
2013-10-25 07:47:31.230 [DEBUG] Rollback RegisterDnsOp (pid:19354)
2013-10-25 07:47:31.231 [DEBUG] DYNECT Login with path: /REST/Session/ (pid:19354)
2013-10-25 07:47:31.883 [DEBUG] DYNECT Response: {"status": "success", "data": {"token": "B6x1Y1QZ5bOjdexbiRdNauJatfXVk8z7fX5OUmmG+4LK999v591mnl/uihh8XIJF1z6qUAwmtiHEYkvqPBxq1ZZ1i2jc+fkE6St3DUpbAJKHvW7a185vgOyw4TnDF3R/Ly4HER3/8DbozmLxnENaMn2ALseZGPSr", "version": "3.5.3"}, "job_id": 537235421, "msgs": [{"INFO": "login: Login successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:19354)
2013-10-25 07:47:31.883 [DEBUG] DYNECT Response data: {"token"=>"B6x1Y1QZ5bOjdexbiRdNauJatfXVk8z7fX5OUmmG+4LK999v591mnl/uihh8XIJF1z6qUAwmtiHEYkvqPBxq1ZZ1i2jc+fkE6St3DUpbAJKHvW7a185vgOyw4TnDF3R/Ly4HER3/8DbozmLxnENaMn2ALseZGPSr", "version"=>"3.5.3"} (pid:19354)
2013-10-25 07:47:31.883 [DEBUG] Dynect Response Time (dyn_login): 0.651996989s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:31.883 [DEBUG] DYNECT delete with path: /REST/CNAMERecord/int.rhcloud.com/526a5a0403ef64b8a70001b5-wjiangint.int.rhcloud.com/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:19354)
2013-10-25 07:47:32.417 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537235429, "msgs": [{"INFO": "delete: 1 records deleted", "SOURCE": "API-B", "ERR_CD": null, "LVL": "INFO"}]} (pid:19354)
2013-10-25 07:47:32.417 [DEBUG] DYNECT Response data: {} (pid:19354)
2013-10-25 07:47:32.417 [DEBUG] Dynect Response Time (dyn_delete): 0.533619077s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:32.417 [DEBUG] DYNECT put/post with path: /REST/Zone/int.rhcloud.com/ json data: {"publish":"true"} and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:19354)
2013-10-25 07:47:33.174 [DEBUG] DYNECT Response: {"status": "success", "data": {"zone_type": "Primary", "serial_style": "day", "serial": 2013220718, "zone": "int.rhcloud.com"}, "job_id": 537235443, "msgs": [{"INFO": "publish: int.rhcloud.com published", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:19354)
2013-10-25 07:47:33.174 [DEBUG] DYNECT Response data: {"zone_type"=>"Primary", "serial_style"=>"day", "serial"=>2013220718, "zone"=>"int.rhcloud.com"} (pid:19354)
2013-10-25 07:47:33.174 [DEBUG] Dynect Response Time (dyn_put_post): 0.756868366s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:33.174 [DEBUG] DYNECT delete with path: /REST/Session/ and headers: {"Content-Type"=>"application/json", "Auth-Token"=>"[hidden]"} (pid:19354)
2013-10-25 07:47:33.632 [DEBUG] DYNECT Response: {"status": "success", "data": {}, "job_id": 537235455, "msgs": [{"INFO": "logout: Logout successful", "SOURCE": "BLL", "ERR_CD": null, "LVL": "INFO"}]} (pid:19354)
2013-10-25 07:47:33.632 [DEBUG] DYNECT Response data: {} (pid:19354)
2013-10-25 07:47:33.632 [DEBUG] Dynect Response Time (dyn_delete): 0.458196484s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:33.673 [DEBUG] Rollback CreateGearOp (pid:19354)
2013-10-25 07:47:33.676 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"openshift-origin-node", :action=>"app-destroy", :args=>{"--with-app-uuid"=>"5260d86303ef642f2b000236", "--with-app-name"=>"py33spsql", "--with-container-uuid"=>"526a5a0403ef64b8a70001b5", "--with-container-name"=>"526a5a0403ef64b8a70001b5", "--with-namespace"=>"wjiangint", "--with-uid"=>1754, "--with-request-id"=>"0e5e8858108724b0800e5445744da83d", "--cart-name"=>"openshift-origin-node"}}, ex-std-node2.int.rhcloud.com, {'identity' => ex-std-node2.int.rhcloud.com}) (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:37.551 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000007931708 @agent="openshift", @action="cartridge_do", @results={:sender=>"ex-std-node2.int.rhcloud.com", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:37.552 [DEBUG] DEBUG: MCollective Response Time (execute_direct: app-destroy): 3.877299774s  (Request ID: 0e5e8858108724b0800e5445744da83d) (pid:19354)
2013-10-25 07:47:37.593 [DEBUG] Rollback ReserveGearUidOp (pid:19354)
2013-10-25 07:47:37.646 [DEBUG] Rollback InitGearOp (pid:19354)
2013-10-25 07:47:37.690 [ERROR] Reference ID: 0e5e8858108724b0800e5445744da83d - Node execution failure (invalid exit code from node).
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:2718:in `parse_result'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.2/lib/openshift/mcollective_application_container_proxy.rb:1738:in `update_cluster'
  /opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:518:in `block in update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'
  /opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:268:in `trace_execution_scoped'
  /opt/rh/ruby193/root/usr/share/gems/gems/newrelic_rpm-3.6.6.147/lib/new_relic/agent/method_tracer.rb:513:in `update_cluster_with_trace_Custom_OpenShift_MCollectiveApplicationContainerProxy_update_cluster'
Comment 8 Andy Goldstein 2013-10-30 14:36:25 UTC 
1) NoMethodError: undefined method `join' for nil:NilClass
There was a bug in the way we processed errors coming back from 'gear activate'. The error processing bug has been fixed by https://github.com/openshift/origin-server/pull/4032. Whatever the underlying cause for 'gear activate' failing may still be there - this PR does not address that.

2) NoMethodError: undefined method `each_value' for nil:NilClass
This shows up when the update-cluster op is rolled back and the gear registry it's rolling back to appears to have 0 gears in it. I need to look more into why the rollback was occurring.

3) NoMethodError: undefined method `keys' for nil:NilClass
As best I can tell, this happened if an application was created where the web cartridge's manifest had been modified so the min scaling value was >= 2. This will be fixed when https://github.com/openshift/origin-server/pull/4047 is merged in to master.

4) TypeError: can't convert nil into String
This happens when update-cluster is attempting to sync deployments and activate whatever the current deployment is on the proxy gear on all new gears during scale up. I looked at the most recent occurrence of this error (from 10/28) and the app in question has a broken app-deployments/current symlink. I'm not sure how it got in this state - it's possible that this app hit a bug during a previous migration, or it's possible that a deployment was started but failed. Either way, the app is "broken" and won't be able to scale up until the app-deployments/current symlink is fixed.
Comment 9 Andy Goldstein 2013-10-30 19:52:30 UTC 
For #2, I am seeing this happen in 2 different ways:

a) MCollective was restarted in the middle of an existing update-cluster invocation, and the broker never gets the response, so it issues the rollback

b) There are infrequent permission denied errors running update-cluster where the HAProxy cartridge is trying to use the Ruby SDK to read the primary cartridge's manifest.yml file.
Comment 10 Andy Goldstein 2013-10-30 20:40:35 UTC 
Marking ON_QA. If there are future exceptions, please create a bz for each one separately - thanks!

Also, #2b from Comment 9 is captured in https://bugzilla.redhat.com/show_bug.cgi?id=1025043
Comment 11 Meng Bo 2013-10-31 10:42:28 UTC 
According to Comment8 9 10, the exceptions are addressed by different bugs and some of them are waiting for PR merged.

move the bug to verified.
Note You need to log in before you can comment on or make changes to this bug.