Description of problem: Exception reported from INT from a call to ApplicationsController#create NoMethodError: undefined method `external_port' for nil:NilClass …b/openshift/ mcollective_application_container_proxy.rb:1725:in `block in build_update_cluster_args' …b/openshift/ mcollective_application_container_proxy.rb:1720:in `each' …b/openshift/ mcollective_application_container_proxy.rb:1720:in `build_update_cluster_args' …b/openshift/ mcollective_application_container_proxy.rb:1736:in `update_cluster' …/openshift-origin-controller-1.16.4/app/models/ gear.rb: 267:in `method_missing' …ift-origin-controller-1.16.4/app/models/ application.rb:1255:in `update_cluster' …ems/gems/mongoid-3.0.21/lib/mongoid/relations/ proxy.rb: 143:in `method_missing' …ler-1.16.4/app/models/pending_ops/ update_cluster_op.rb: 4:in `execute' …n-controller-1.16.4/app/models/ pending_app_op_group.rb: 75:in `block in execute' …n-controller-1.16.4/app/models/ pending_app_op_group.rb: 64:in `each' …n-controller-1.16.4/app/models/ pending_app_op_group.rb: 64:in `execute' …ift-origin-controller-1.16.4/app/models/ application.rb:1538:in `run_jobs' …ift-origin-controller-1.16.4/app/models/ application.rb: 660:in `block in add_features' …ift-origin-controller-1.16.4/app/models/ application.rb:1584:in `run_in_application_lock' …ift-origin-controller-1.16.4/app/models/ application.rb: 653:in `add_features' …ift-origin-controller-1.16.4/app/models/ application.rb: 251:in `create_app' …ller-1.16.4/app/controllers/ applications_controller.rb: 147:in `create' …ntroller-1.16.4/lib/openshift/controller/ action_log.rb: 80:in `set_logged_request' …sr/share/gems/gems/journey-1.0.4/lib/journey/ router.rb: 68:in `block in call' …sr/share/gems/gems/journey-1.0.4/lib/journey/ router.rb: 56:in `each' …sr/share/gems/gems/journey-1.0.4/lib/journey/ router.rb: 56:in `call' …per-0.11.1/lib/mongo_mapper/middleware/ identity_map.rb: 10:in `call' …oid-3.0.21/lib/rack/mongoid/middleware/ identity_map.rb: 34:in `block in call' …e/gems/gems/mongoid-3.0.21/lib/mongoid/ unit_of_work.rb: 39:in `unit_of_work' …oid-3.0.21/lib/rack/mongoid/middleware/ identity_map.rb: 34:in `call' …3/root/usr/share/gems/gems/rack-1.4.1/lib/rack/ etag.rb: 23:in `call' …/share/gems/gems/rack-1.4.1/lib/rack/ conditionalget.rb: 35:in `call' …e/gems/gems/rack-1.4.1/lib/rack/session/abstract/ id.rb: 205:in `context' …e/gems/gems/rack-1.4.1/lib/rack/session/abstract/ id.rb: 200:in `call' …/share/gems/gems/rack-1.4.1/lib/rack/ methodoverride.rb: 21:in `call' …oot/usr/share/gems/gems/rack-1.4.1/lib/rack/ runtime.rb: 17:in `call' …3/root/usr/share/gems/gems/rack-1.4.1/lib/rack/ lock.rb: 15:in `call' …are/gems/gems/rack-cache-1.2/lib/rack/cache/ context.rb: 136:in `forward' …are/gems/gems/rack-cache-1.2/lib/rack/cache/ context.rb: 143:in `pass' …are/gems/gems/rack-cache-1.2/lib/rack/cache/ context.rb: 155:in `invalidate' …are/gems/gems/rack-cache-1.2/lib/rack/cache/ context.rb: 71:in `call!' …are/gems/gems/rack-cache-1.2/lib/rack/cache/ context.rb: 51:in `call' …r-3.0.21/lib/phusion_passenger/rack/ request_handler.rb: 97:in `process_request' …0.21/lib/phusion_passenger/ abstract_request_handler.rb: 521:in `accept_and_process_next_request' …0.21/lib/phusion_passenger/ abstract_request_handler.rb: 274:in `main_loop' …0.21/lib/phusion_passenger/rack/ application_spawner.rb: 206:in `start_request_handler' …0.21/lib/phusion_passenger/rack/ application_spawner.rb: 79:in `block in spawn_application' …s/gems/passenger-3.0.21/lib/phusion_passenger/ utils.rb: 470:in `safe_fork' …0.21/lib/phusion_passenger/rack/ application_spawner.rb: 64:in `spawn_application' …assenger-3.0.21/lib/phusion_passenger/ spawn_manager.rb: 264:in `spawn_rack_application' …assenger-3.0.21/lib/phusion_passenger/ spawn_manager.rb: 137:in `spawn_application' …assenger-3.0.21/lib/phusion_passenger/ spawn_manager.rb: 275:in `handle_spawn_application' …senger-3.0.21/lib/phusion_passenger/ abstract_server.rb: 357:in `server_main_loop' …senger-3.0.21/lib/phusion_passenger/ abstract_server.rb: 206:in `start_synchronously'
So far I've only seen this happen when the previous operation, expose-port, hits the 240 second MCollective timeout. For some reason the expose-port operation isn't considered a failure, and update-cluster is executed. update-cluster requires that all web gears in Mongo have at least one port_interface. Because expose-port doesn't complete successfully, the gears have 0 port_interfaces, and we see this exception.
Fixed with https://github.com/openshift/origin-server/pull/4052 Expose port failures will not be ignored any more and the app create will fail nicely.
Verified on devenv_3973 Added "sleep 300" in //opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.16.4/lib/openshift/mcollective_application_container_proxy.rb to make mcollective timeout, according to development.rb, the action hangs there and the exepose-port op is not executed successfully, and application is not available after creation. Change the code back, and restart mcollective/broker services, the pending_op is executed and app became available after a short time. Make as verified Appended development.log <-- development.log --> 2013-10-31 01:20:43.140 [DEBUG] Execute PostConfigureCompOp (pid:32618) 2013-10-31 01:20:43.197 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"haproxy-1.4", :action=>"post-configure", :args=>{"--with-app-uuid"=>"5271e75f83b701a8b1000001", "--with-app-name"=>"php1s", "--with-container-uuid"=>"5271e75f83b701a8b1000001", "--with-container-name"=>"php1s", "--with-namespace"=>"jhou", "--with-uid"=>4410, "--with-request-id"=>"092d8f09106b0cf6ff541a1fd819867f", "--cart-name"=>"haproxy-1.4", "--component-name"=>"web_proxy", "--with-software-version"=>"1.4", "--cartridge-vendor"=>"redhat"}}, ip-10-82-221-10, {'identity' => ip-10-82-221-10}) (Request ID: 092d8f09106b0cf6ff541a1fd819867f) (pid:32618) 2013-10-31 01:20:46.204 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000005a7f940 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-82-221-10", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"HAProxy instance is started\n", :exitcode=>0, :addtl_params=>nil}}>] (Request ID: 092d8f09106b0cf6ff541a1fd819867f) (pid:32618) 2013-10-31 01:20:46.206 [DEBUG] DEBUG: MCollective Response Time (execute_direct: post-configure): 3.010714897s (Request ID: 092d8f09106b0cf6ff541a1fd819867f) (pid:32618) 2013-10-31 01:20:46.251 [DEBUG] Execute ExposePortOp (pid:32618) <-- end of development.log -->