Attachment 672820 Details for Bug 892124 – development.log

development.log

file_892124.txt (text/plain), 15.54 KB, created by Rony Gong 🔥 on 2013-01-05 10:35:24 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Rony Gong 🔥

Created: 2013-01-05 10:35:24 UTC

Size: 15.54 KB

patch

obsolete

>  MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} (23.9234ms)
>  MOPED: 127.0.0.1:27017 INSERT       database=openshift_broker_dev collection=system.indexes documents=[{:unique=>true, :ns=>"openshift_broker_dev.domains", :key=>{:namespace=>1}, :name=>"namespace_1"}] flags=[] (0.4094ms)
>  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=[] (0.6020ms)
>2013-01-05 05:01:33.932 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=applications selector={"$query"=>{"group_instances.gears._id"=>"50e7f0c0776856a80800053c"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (1.3945ms) (pid:5973)
>2013-01-05 05:01:33.937 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"$query"=>{"_id"=>"50e79621776856a808000004"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.8278ms) (pid:5973)
>2013-01-05 05:01:33.941 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"$query"=>{"_id"=>"50e7960b776856a808000001"}, "$orderby"=>{:_id=>1}} flags=[:slave_ok] limit=-1 skip=0 fields=nil (0.8755ms) (pid:5973)
>2013-01-05 05:01:33.945 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"owner_id"=>"50e7960b776856a808000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.7808ms) (pid:5973)
>2013-01-05 05:01:33.946 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=domains selector={"user_ids"=>"50e7960b776856a808000001"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.4768ms) (pid:5973)
>2013-01-05 05:01:33.948 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"50e7960b776856a808000001", "app_ids"=>{"$nin"=>["50e7ef79776856a8080004f6"]}}, :new=>true, :update=>{"$push"=>{:app_ids=>"50e7ef79776856a8080004f6"}}} (0.9329ms) (pid:5973)
>2013-01-05 05:01:34.645 [DEBUG] DEBUG: Source district uuid: 50e79b17776856de32000001 (pid:5973)
>2013-01-05 05:01:34.646 [DEBUG] DEBUG: Destination district uuid: 50e79b17776856de32000001 (pid:5973)
>2013-01-05 05:01:34.646 [DEBUG] DEBUG: District unchanged keeping uid (pid:5973)
>2013-01-05 05:01:34.873 [DEBUG] DEBUG: Getting existing app 'qs2php' status before moving (pid:5973)
>2013-01-05 05:01:34.883 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006079d50> (pid:5973)
>2013-01-05 05:01:34.883 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"php-5.3", :action=>"status", :args=>"'qs2php' 'qgong8' '50e7ef79776856a8080004f6'"}, ip-10-100-222-253, {'identity' => ip-10-100-222-253}) (pid:5973)
>2013-01-05 05:01:35.556 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000061dcfd0 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-100-222-253", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"CLIENT_RESULT: Total Accesses: 501\nCLIENT_RESULT: Total kBytes: 2554\nCLIENT_RESULT: CPULoad: .0418327\nCLIENT_RESULT: Uptime: 1004\nCLIENT_RESULT: ReqPerSec: .499004\nCLIENT_RESULT: BytesPerSec: 2604.88\nCLIENT_RESULT: BytesPerReq: 5220.15\nCLIENT_RESULT: BusyWorkers: 1\nCLIENT_RESULT: IdleWorkers: 1\nCLIENT_RESULT: Scoreboard: _W...\nATTR: quota_blocks=1048576\nATTR: quota_files=40000\n", :exitcode=>0}}>] (pid:5973)
>2013-01-05 05:01:35.560 [DEBUG] DEBUG: Gear component 'php-5.3' was running (pid:5973)
>2013-01-05 05:01:35.569 [DEBUG] DEBUG: Stopping existing app cartridge 'haproxy-1.4' before moving (pid:5973)
>2013-01-05 05:01:35.575 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x00000006472448> (pid:5973)
>2013-01-05 05:01:35.575 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"embedded/haproxy-1.4", :action=>"stop", :args=>"'50e7f0c077' 'qgong8' '50e7f0c0776856a80800053c'"}, ip-10-100-222-253, {'identity' => ip-10-100-222-253}) (pid:5973)
>2013-01-05 05:01:36.340 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x00000006287160 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-100-222-253", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 127. Output /usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found\n", :data=>{:time=>nil, :output=>"/usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found\n", :exitcode=>127}}>] (pid:5973)
>2013-01-05 05:01:36.341 [DEBUG] DEBUG: server results: /usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found (pid:5973)
>2013-01-05 05:01:36.342 [DEBUG] DEBUG: Error performing stop on existing app on try 1: Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:5973)
>2013-01-05 05:01:36.344 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x0000000607dec8> (pid:5973)
>2013-01-05 05:01:36.344 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"embedded/haproxy-1.4", :action=>"stop", :args=>"'50e7f0c077' 'qgong8' '50e7f0c0776856a80800053c'"}, ip-10-100-222-253, {'identity' => ip-10-100-222-253}) (pid:5973)
>2013-01-05 05:01:37.446 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000062f0ea8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-100-222-253", :statuscode=>1, :statusmsg=>"cartridge_do_action failed 127. Output /usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found\n", :data=>{:time=>nil, :output=>"/usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found\n", :exitcode=>127}}>] (pid:5973)
>2013-01-05 05:01:37.447 [DEBUG] DEBUG: server results: /usr/libexec/openshift/cartridges/haproxy-1.4/info/bin/app_ctl.sh: line 63: haproxy_ctld_daemon: command not found (pid:5973)
>2013-01-05 05:01:37.448 [DEBUG] DEBUG: Error performing stop on existing app on try 2: Node execution failure (invalid exit code from node).  If the problem persists please contact Red Hat support. (pid:5973)
>2013-01-05 05:01:37.457 [DEBUG] DEBUG: rpc_exec_direct: rpc_client=#<MCollective::RPC::Client:0x000000062c8e80> (pid:5973)
>2013-01-05 05:01:37.458 [DEBUG] DEBUG: rpc_client.custom_request('cartridge_do', {:cartridge=>"php-5.3", :action=>"start", :args=>"'50e7f0c077' 'qgong8' '50e7f0c0776856a80800053c'"}, ip-10-100-222-253, {'identity' => ip-10-100-222-253}) (pid:5973)
>2013-01-05 05:01:38.881 [DEBUG] DEBUG: [#<MCollective::RPC::Result:0x000000063551c8 @agent="openshift", @action="cartridge_do", @results={:sender=>"ip-10-100-222-253", :statuscode=>0, :statusmsg=>"OK", :data=>{:time=>nil, :output=>"httpd (pid 19715) already running\n", :exitcode=>0}}>] (pid:5973)
>2013-01-05 05:01:38.886 [DEBUG] MOPED: 127.0.0.1:27017 COMMAND      database=openshift_broker_dev command={:findAndModify=>"locks", :query=>{"user_id"=>"50e7960b776856a808000001", "locked"=>false, "app_ids"=>{"$in"=>["50e7ef79776856a8080004f6"]}}, :new=>false, :update=>{"$pop"=>{:app_ids=>"50e7ef79776856a8080004f6"}}} (2.0597ms) (pid:5973)
>2013-01-05 05:01:39.378 [INFO ] Started GET "/broker/rest/domains/qgong8/applications/qs2php" for 127.0.0.1 at 2013-01-05 05:01:39 -0500 (pid:2216)
>2013-01-05 05:01:39.382 [INFO ] Processing by ApplicationsController#show as JSON (pid:2216)
>2013-01-05 05:01:39.382 [INFO ] Parameters: {"broker_auth_key"=>"[FILTERED]", "broker_auth_iv"=>"[FILTERED]", "domain_id"=>"qgong8", "id"=>"qs2php"} (pid:2216)
>2013-01-05 05:01:39.390 [DEBUG] MOPED: 127.0.0.1:27017 QUERY        database=openshift_broker_dev collection=cloud_users selector={"_id"=>"qgong@redhat.com"} flags=[:slave_ok] limit=0 skip=0 fields=nil (0.5751ms) (pid:2216)
>2013-01-05 05:01:39.390 [INFO ] Completed 500 Internal Server Error in 9ms (pid:2216)
>2013-01-05 05:01:39.394 [FATAL] Mongoid::Errors::DocumentNotFound (
>Problem:
>  Document(s) not found for class CloudUser with id(s) qgong@redhat.com.
>Summary:
>  When calling CloudUser.find with an id or array of ids, each parameter must match a document in the database or this error will be raised. The search was for the id(s): qgong@redhat.com ... (1 total) and the following ids were not found: qgong@redhat.com.
>Resolution:
>  Search for an id that is in the database or set the Mongoid.raise_not_found_error configuration option to false, which will cause a nil to be returned instead of raising this error when searching for a single id, or only the matched documents when searching for multiples.):
>  mongoid (3.0.5) lib/mongoid/criteria.rb:553:in `check_for_missing_documents!'
>  mongoid (3.0.5) lib/mongoid/criteria.rb:177:in `execute_or_raise'
>  mongoid (3.0.5) lib/mongoid/criteria.rb:243:in `find'
>  mongoid (3.0.5) lib/mongoid/finders.rb:61:in `find'
>  openshift-origin-controller (1.3.2) lib/openshift/auth_service.rb:79:in `validate_broker_key'
>  openshift-origin-auth-streamline (1.2.1) lib/openshift/streamline_auth_service.rb:23:in `authenticate'
>  openshift-origin-controller (1.3.2) app/controllers/base_controller.rb:106:in `authenticate'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:429:in `_run__3728756251093986192__process_action__1495512691900177830__callbacks'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
>  actionpack (3.2.8) lib/abstract_controller/callbacks.rb:17:in `process_action'
>  actionpack (3.2.8) lib/action_controller/metal/rescue.rb:29:in `process_action'
>  actionpack (3.2.8) lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
>  activesupport (3.2.8) lib/active_support/notifications.rb:123:in `block in instrument'
>  activesupport (3.2.8) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
>  activesupport (3.2.8) lib/active_support/notifications.rb:123:in `instrument'
>  actionpack (3.2.8) lib/action_controller/metal/instrumentation.rb:29:in `process_action'
>  actionpack (3.2.8) lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
>  actionpack (3.2.8) lib/abstract_controller/base.rb:121:in `process'
>  actionpack (3.2.8) lib/abstract_controller/rendering.rb:45:in `process'
>  actionpack (3.2.8) lib/action_controller/metal.rb:203:in `dispatch'
>  actionpack (3.2.8) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
>  actionpack (3.2.8) lib/action_controller/metal.rb:246:in `block in action'
>  actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:73:in `call'
>  actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
>  actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:36:in `call'
>  journey (1.0.4) lib/journey/router.rb:68:in `block in call'
>  journey (1.0.4) lib/journey/router.rb:56:in `each'
>  journey (1.0.4) lib/journey/router.rb:56:in `call'
>  actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:600:in `call'
>  mongo_mapper (0.11.1) lib/mongo_mapper/middleware/identity_map.rb:10:in `call'
>  mongoid (3.0.5) lib/rack/mongoid/middleware/identity_map.rb:33:in `block in call'
>  mongoid (3.0.5) lib/mongoid/unit_of_work.rb:39:in `unit_of_work'
>  mongoid (3.0.5) lib/rack/mongoid/middleware/identity_map.rb:33:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
>  rack (1.4.1) lib/rack/etag.rb:23:in `call'
>  rack (1.4.1) lib/rack/conditionalget.rb:25:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/head.rb:14:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/params_parser.rb:21:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/flash.rb:242:in `call'
>  rack (1.4.1) lib/rack/session/abstract/id.rb:205:in `context'
>  rack (1.4.1) lib/rack/session/abstract/id.rb:200:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/cookies.rb:339:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `_run__940890698564357668__call__2569289519228783109__callbacks'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
>  activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
>  actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
>  actionpack (3.2.8) lib/action_dispatch/middleware/debug_exceptions.rb:16: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.12) lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
>  passenger (3.0.12) lib/phusion_passenger/abstract_request_handler.rb:514:in `accept_and_process_next_request'
>  passenger (3.0.12) lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
>  passenger (3.0.12) lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
>  passenger (3.0.12) lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'
>  passenger (3.0.12) lib/phusion_passenger/utils.rb:479:in `safe_fork'
>  passenger (3.0.12) lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'
>  passenger (3.0.12) lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'
>  passenger (3.0.12) lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
>  passenger (3.0.12) lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
>  passenger (3.0.12) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
>  passenger (3.0.12) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
>  passenger (3.0.12) helper-scripts/passenger-spawn-server:102:in `<main>' (pid:2216)
>2013-01-05 05:01:39.409 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_trace.erb (1.8ms) (pid:2216)
>2013-01-05 05:01:39.414 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (1.7ms) (pid:2216)
>2013-01-05 05:01:39.414 [INFO ] Rendered /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (11.8ms) (pid:2216)
>^C

Actions: View

Attachments on bug 892124: 672820