Bug 977037 - Broker is returning HTTP instead of JSON error response for a node failure
Summary: Broker is returning HTTP instead of JSON error response for a node failure
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OKD
Classification: Red Hat
Component: Master
Version: 2.x
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: ---
Assignee: Lili Nader
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-06-22 20:19 UTC by Clayton Coleman
Modified: 2015-05-15 00:54 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-07-22 15:12:43 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)

Description Clayton Coleman 2013-06-22 20:19:48 UTC 
The failure described below (caused by running rm -rf * within a scaled db gear and then attempting to remove the db cartridge) is being returned by the broker as HTML, but should be rescued by the REST API and the proper response returned.  

High severity because uncaught exceptions make debugging difficult in production and the clients can't report accurate info.

  OpenShift::NodeException
    in EmbCartController#destroy
</h1>
<pre>Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support.</pre>


<p><code>Rails.root: /var/www/openshift/broker</code></p>

<div id="traces">
    <a href="#" onclick="document.getElementById(&#x27;Framework-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Full-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Application-Trace&#x27;).style.display=&#x27;block&#x27;;; return false;">Application Trace</a> |
    <a href="#" onclick="document.getElementById(&#x27;Application-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Full-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Framework-Trace&#x27;).style.display=&#x27;block&#x27;;; return false;">Framework Trace</a> |
    <a href="#" onclick="document.getElementById(&#x27;Application-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Framework-Trace&#x27;).style.display=&#x27;none&#x27;;document.getElementById(&#x27;Full-Trace&#x27;).style.display=&#x27;block&#x27;;; return false;">Full Trace</a> 

    <div id="Application-Trace" style="display: block;">
      <pre><code>lib/online/broker/mcollective_ext.rb:26:in `destroy&#x27;</code></pre>
    </div>
    <div id="Framework-Trace" style="display: none;">
      <pre><code>openshift-origin-msg-broker-mcollective (1.10.3) lib/openshift/mcollective_application_container_proxy.rb:2633:in `parse_result&#x27;
openshift-origin-msg-broker-mcollective (1.10.3) lib/openshift/mcollective_application_container_proxy.rb:440:in `destroy&#x27;
openshift-origin-controller (1.10.5) app/models/gear.rb:83:in `destroy_gear&#x27;
openshift-origin-controller (1.10.5) app/models/pending_app_op_group.rb:225:in `block in execute&#x27;
openshift-origin-controller (1.10.5) app/models/pending_app_op_group.rb:155:in `each&#x27;
openshift-origin-controller (1.10.5) app/models/pending_app_op_group.rb:155:in `execute&#x27;
openshift-origin-controller (1.10.5) app/models/application.rb:1256:in `run_jobs&#x27;
Comment 1 Clayton Coleman 2013-06-22 20:20:45 UTC 
The status msg from the node contained useful information for the user that was lost by the broker not rescuing the exception.

2013-06-22 16:17:34.658 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000061ba700 @agent="op
enshift", @action="cartridge_do", @results={:sender=>"ip-10-98-178-76", :statuscode=>1, :statu
smsg=>"cartridge_do_action failed -1. Output 'redis:2.6:0.0.1\n' is not a legal cartridge iden
tifier", :data=>{:time=>nil, :output=>"'redis:2.6:0.0.1\n' is not a legal cartridge identifier
", :exitcode=>-1}}>] (Request ID: 0f6ffc5ec52d7615b8af8e135a40d9f5) (pid:2936)
2013-06-22 16:17:34.659 [DEBUG] DEBUG: MCollective Response Time (execute_direct: app-destroy)
: 0.070794397s  (Request ID: 0f6ffc5ec52d7615b8af8e135a40d9f5) (pid:2936)
2013-06-22 16:17:34.659 [DEBUG] DEBUG: server results: 'redis:2.6:0.0.1 (pid:2936)
2013-06-22 16:17:34.659 [DEBUG] DEBUG: server results: ' is not a legal cartridge identifier (
pid:2936)
2013-06-22 16:17:34.659 [ERROR] Node execution failure (invalid exit code from node).  If the 
problem persists please contact Red Hat support. (pid:2936)
2013-06-22 16:17:34.659 [ERROR] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-ms
g-broker-mcollective-1.10.3/lib/openshift/mcollective_application_container_proxy.rb:2633:in `
parse_result'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollect
ive-1.10.3/lib/openshift/mcollective_application_container_proxy.rb:440:in `destroy'", "/var/w
ww/openshift/broker/lib/online/broker/mcollective_ext.rb:26:in `destroy'", "/opt/rh/ruby193/ro
ot/usr/share/gems/gems/openshift-origin-controller-1.10.5/app/models/
Comment 2 Lili Nader 2013-06-25 17:15:53 UTC 
Fixed on broker to return HTTP status code 500.

https://github.com/openshift/origin-server/pull/2923
Comment 3 Lili Nader 2013-06-25 17:17:49 UTC 
Should this be fixed on node as well? It is preventing app from being deleted.
Comment 4 Jhon Honce 2013-06-25 17:20:05 UTC 
There is a bug already against the node covering this.
Comment 5 openshift-github-bot 2013-06-25 17:22:19 UTC 
Commit pushed to master at https://github.com/openshift/origin-server

https://github.com/openshift/origin-server/commit/552ad8582c014d121b29667d4020dca6feca03f8
Bug 977037
Comment 6 zhaozhanqi 2013-06-26 09:11:43 UTC 
Test this bug on devenv_3414, it has been fixed

 steps:
 
  1) create scalable app with mysql db
  2) remove the gear directory of DB 
 [zqzhao@dhcp-13-222 origin-server]$ rhc app show zqphps -g
ID                               State   Cartridges          Size  SSH URL
-------------------------------- ------- ------------------- ----- ---------------------------------------------------------------------
f3df644ede3e11e2b5a312313d04dd1a started php-5.3 haproxy-1.4 small f3df644ede3e11e2b5a312313d04dd1a.rhcloud.com
51caae2732a11f071b000015         started mysql-5.1           small 51caae2732a11f071b000015.rhcloud.com

ssh into instance:

[root@ip-10-114-234-232 openshift]# mv 51caae2732a11f071b000015 51caae2732a11f071b000016



  3) remove the db cartridge from the app

 [zqzhao@dhcp-13-222 origin-server]$ rhc cartridge remove -a zqphps -c mysql-5.1 
Removing a cartridge is a destructive operation that may result in loss of data associated with the cartridge.

Are you sure you wish to remove mysql-5.1 from 'zqphps'? (yes|no): yes

Removing mysql-5.1 from 'zqphps' ... removed

Removed mysql-5.1 from application zqphps
Comment 7 Jianwei Hou 2013-06-26 10:33:50 UTC 
Verified on devenv_3414

Steps:
1. Create scaled application with db cartridge
2. Remove the OPENSHIFT_*_IDENT from the cartridge of the gear
3. Remove the db cartridge from CLI

Result:
Notice in development.log, the json error is returned

013-06-26 06:27:31.850 [ERROR] Reference ID: 1356c3ff9fc9be8db71f64d31994fd0b - Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support.
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.11.1/lib/openshift/mcollective_application_container_proxy.rb:2633:in `parse_result'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.11.1/lib/openshift/mcollective_application_container_proxy.rb:440:in `destroy'
  /var/www/openshift/broker/lib/online/broker/mcollective_ext.rb:26:in `destroy'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/gear.rb:83:in `destroy_gear'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/pending_app_op_group.rb:225:in `block in execute'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/pending_app_op_group.rb:155:in `each'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/pending_app_op_group.rb:155:in `execute'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/application.rb:1256:in `run_jobs'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/application.rb:546:in `block in remove_features'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/application.rb:1298:in `run_in_application_lock'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/models/application.rb:544:in `remove_features'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/app/controllers/emb_cart_controller.rb:166:in `destroy'
  /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:492:in `block in _run__1360680083845317673__process_action__2276827402514982868__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_379'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.11.1/lib/openshift/controller/action_log.rb:34:in `set_logged_request'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_379'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__1360680083845317673__process_action__2276827402514982868__callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
  /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
  /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/mongo_mapper-0.11.1/lib/mongo_mapper/middleware/identity_map.rb:10:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `block in call'
  /opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/unit_of_work.rb:39:in `unit_of_work'
  /opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/rack/mongoid/middleware/identity_map.rb:34:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__1308905490714815867__call__3729110008269705191__callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'
  /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
  /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'
  /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:517:in `accept_and_process_next_request'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/utils.rb:470:in `safe_fork'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/passenger-spawn-server:102:in `<main>' (pid:1819)
2013-06-26 06:27:31.851 [DEBUG] FAILURE ACTION=DELETE_APP_CARTRIDGE USER_ID=51cab2b532a11f13570004c0 LOGIN=jhou APP=php1s DOMAIN=jhou APP_UUID=985854488065997547765760 Unable to complete the requested operation due to: Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support..
Reference ID: 1356c3ff9fc9be8db71f64d31994fd0b (pid:1819)
2013-06-26 06:27:31.853 [INFO ] Completed 500 Internal Server Error in 361ms (Views: 0.6ms) (pid:1819)
Note You need to log in before you can comment on or make changes to this bug.