Bug 902286

Summary: Broker reports RoutingError on restart
Product: OKD Reporter: Jianwei Hou <jhou>
Component: PodAssignee: Dan McPherson <dmcphers>
Status: CLOSED CURRENTRELEASE QA Contact: libra bugs <libra-bugs>
Severity: low Docs Contact:
Priority: low    
Version: 2.x   
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-14 00:57:47 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
development.log none

Description Jianwei Hou 2013-01-21 10:09:35 UTC
Created attachment 684200 [details]
development.log

Description of problem:
When restarting rhc-broker, the "RoutingError" is continuously seen.

Version-Release number of selected component (if applicable):
On devenv_2699

How reproducible:
Always

Steps to Reproduce:
1. tailf development.log and restart broker
  
Actual results:
The broker reports error when it's being restarted

[INFO ] Started GET "/broker" for 127.0.0.1 at 2013-01-21 05:07:37 -0500 (pid:20929)
2013-01-21 05:07:37.332 [FATAL] ActionController::RoutingError (No route matches [GET] "/"):
  actionpack (3.2.8) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
  railties (3.2.8) lib/rails/rack/logger.rb:26:in `call_app'
  railties (3.2.8) lib/rails/rack/logger.rb:16:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/request_id.rb:22:in `call'
  rack (1.4.1) lib/rack/methodoverride.rb:21:in `call'
  rack (1.4.1) lib/rack/runtime.rb:17:in `call'
  activesupport (3.2.8) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  rack (1.4.1) lib/rack/lock.rb:15:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/static.rb:62:in `call'
  rack-cache (1.2) lib/rack/cache/context.rb:136:in `forward'
  rack-cache (1.2) lib/rack/cache/context.rb:245:in `fetch'
  rack-cache (1.2) lib/rack/cache/context.rb:185:in `lookup'
  rack-cache (1.2) lib/rack/cache/context.rb:66:in `call!'
  rack-cache (1.2) lib/rack/cache/context.rb:51:in `call'
  railties (3.2.8) lib/rails/engine.rb:479:in `call'
  railties (3.2.8) lib/rails/application.rb:223:in `call'
  railties (3.2.8) lib/rails/railtie/configurable.rb:30:in `method_missing'
  passenger (3.0.17) lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
  passenger (3.0.17) lib/phusion_passenger/abstract_request_handler.rb:517:in `accept_and_process_next_request'
  passenger (3.0.17) lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'
  passenger (3.0.17) lib/phusion_passenger/utils.rb:470:in `safe_fork'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  passenger (3.0.17) helper-scripts/passenger-spawn-server:102:in `<main>' (pid:20929)




Expected results:
Should not see errors in log

Additional info:
development.log is attached.

Comment 1 Dan McPherson 2013-01-28 01:55:24 UTC
https://github.com/openshift/li/pull/799

Comment 4 Jianwei Hou 2013-01-29 01:45:55 UTC
Verified on devenv_2737

The problem is gone when restarting rhc-broker, here are the logs:


  MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (8.0364ms)
  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.gears", :key=>{:uuid=>1}, :name=>"uuid_1"}] flags=[]
                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5603ms)
  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.gears", :key=>{:uuid=>1}, :name=>"uuid_1"}] flags=[]
                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5603ms)
  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.domains", :key=>{:canonical_namespace=>1}, :name=>"canonical_namespace_1"}] flags=[]
                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7761ms)
  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.cloud_users", :key=>{:login=>1}, :name=>"login_1"}] flags=[]
                         COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.5713ms)
2013-01-28 20:44:44.615 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.districts", :key=>{:name=>1}, :name=>"name_1"}] flags=[] (pid:8887)
2013-01-28 20:44:44.615 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.8719ms) (pid:8887)
2013-01-28 20:44:45.236 [DEBUG] MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.distributed_locks", :key=>{:type=>1}, :name=>"type_1"}] flags=[] (pid:8887)
2013-01-28 20:44:45.239 [DEBUG] COMMAND      database=openshift_broker_dev command={:getlasterror=>1, :safe=>true} (0.7176ms) (pid:8887)
2013-01-28 20:44:45.244 [INFO ] Started GET "/broker/rest/api.json" for 127.0.0.1 at 2013-01-28 20:44:45 -0500 (pid:8887)
2013-01-28 20:44:45.526 [INFO ] Processing by BaseController#show as JSON (pid:8887)
2013-01-28 20:44:45.527 [DEBUG]  (pid:8887)
2013-01-28 20:44:45.868 [INFO ] Completed 200 OK in 342ms (Views: 5.6ms) (pid:8887)
2013-01-28 20:44:45.874 [INFO ] Started GET "/broker/rest/api.json" for 127.0.0.1 at 2013-01-28 20:44:45 -0500 (pid:8887)
2013-01-28 20:44:45.881 [INFO ] Processing by BaseController#show as JSON (pid:8887)
2013-01-28 20:44:45.882 [DEBUG]  (pid:8887)
2013-01-28 20:44:45.897 [INFO ] Completed 200 OK in 15ms (Views: 4.4ms) (pid:8887)