Bug 977037 - Broker is returning HTTP instead of JSON error response for a node failure
Broker is returning HTTP instead of JSON error response for a node failure
Status: CLOSED CURRENTRELEASE
Product: OpenShift Origin
Classification: Red Hat
Component: Master (Show other bugs)
2.x
Unspecified Unspecified
unspecified Severity high
: ---
: ---
Assigned To: Lili Nader
libra bugs
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-06-22 16:19 EDT by Clayton Coleman
Modified: 2015-05-14 20:54 EDT (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-07-22 11:12:43 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Clayton Coleman 2013-06-22 16:19:48 EDT
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 16:20:45 EDT
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 13:15:53 EDT
Fixed on broker to return HTTP status code 500.

https://github.com/openshift/origin-server/pull/2923
Comment 3 Lili Nader 2013-06-25 13:17:49 EDT
Should this be fixed on node as well? It is preventing app from being deleted.
Comment 4 Jhon Honce 2013-06-25 13:20:05 EDT
There is a bug already against the node covering this.
Comment 6 zhaozhanqi 2013-06-26 05:11:43 EDT
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@zqphps-zqd.dev.rhcloud.com
51caae2732a11f071b000015         started mysql-5.1           small 51caae2732a11f071b000015@51caae2732a11f071b000015-zqd.dev.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 06:33:50 EDT
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@redhat.com 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.