Bug 1004174

Summary: "[ERROR] DEPRECATED: Access to Application#uuid has been removed" found in development.log when an app is being created
Product: OpenShift Online Reporter: Jianwei Hou <jhou>
Component: PodAssignee: Abhishek Gupta <abhgupta>
Status: CLOSED CURRENTRELEASE QA Contact: libra bugs <libra-bugs>
Severity: medium Docs Contact:
Priority: medium    
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-09-19 16:49:02 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-09-04 07:07:33 UTC
Created attachment 793508 [details]
development.log

Description of problem:
Monitor development.log while an application creation is underway, An error "[ERROR] DEPRECATED: Access to Application#uuid has been removed" will be seen in development.log of broker.
This problem was noticed when I was querying cloud_users collection from mongo and found there is a large queue of pending_ops of _type UserSshKey. The sshkey is added but the pending_ops is not cleared, digged into development.log and found this issue.

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

How reproducible:
Always

Steps to Reproduce:
1. On broker tailf /var/log/openshift/broker/development.log
2. On cli, create an application
rhc create-app $appname $cart


Actual results:
In the development.log, following error will be seen

2013-09-04 02:37:02.311 [ERROR] DEPRECATED: Access to Application#uuid has been removed
  /opt/rh/ruby193/root/usr/share/gems/gems/mongoid-3.0.21/lib/mongoid/relations/proxy.rb:143:in `method_missing'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.14.1/lib/openshift/mcollective_application_container_proxy.rb:313:in `build_base_gear_args'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-msg-broker-mcollective-1.14.1/lib/openshift/mcollective_application_container_proxy.rb:905:in `get_stop_job'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/gear.rb:210:in `method_missing'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/pending_app_op_group.rb:272:in `block in execute'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/pending_app_op_group.rb:172:in `each'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/pending_app_op_group.rb:172:in `execute'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/application.rb:1501:in `run_jobs'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/application.rb:868:in `block in stop'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/application.rb:1546:in `run_in_application_lock'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/models/application.rb:859:in `stop'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/app/controllers/emb_cart_events_controller.rb:21:in `create'
  /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:481:in `block in _run__4561303081757656387__process_action__3538950392690768316__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_396'
  /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.14.1/lib/openshift/controller/action_log.rb:80: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_396'
  /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__4561303081757656387__process_action__3538950392690768316__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/sass-3.1.20/lib/sass/plugin/rack.rb:54: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__3559413986146522747__call__1018353801890716205__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/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62: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.21/lib/phusion_passenger/rack/request_handler.rb:97:in `process_request'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:521:in `accept_and_process_next_request'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:79:in `block in spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/utils.rb:470:in `safe_fork'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/rack/application_spawner.rb:64:in `spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:264:in `spawn_rack_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/passenger-spawn-server:102:in `<main>' (pid:16095)


Expected results:
Should not have any error in log file.

Additional info:

Comment 1 Jianwei Hou 2013-09-04 08:06:10 UTC
Correction, the version is devenv_3740

Comment 2 Abhishek Gupta 2013-09-06 18:01:05 UTC
This error was explicitly logged to catch/identify areas in the code that were using uuid attribute of the application. The error has now been removed. 

This error was just supposed to act as a deprecation warning and cannot cause anything else to fail. The ssh key issue that you refer to is not caused by this error message.

Comment 3 Jianwei Hou 2013-09-09 01:51:56 UTC
Verified on devenv_3758, the error has been removed. Will open another bug to keep track of the ssh key issue.