Bug 1024752

Summary: Backtrace of pending_app_op_group.rb has been repeatedly seen in development.log after migration
Product: OpenShift Online Reporter: Jianwei Hou <jhou>
Component: PodAssignee: Andy Goldstein <agoldste>
Status: CLOSED CURRENTRELEASE QA Contact: libra bugs <libra-bugs>
Severity: medium Docs Contact:
Priority: medium    
Version: 2.xCC: agoldste, jhou, xtian
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: 2014-01-24 03:27:53 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:

Description Jianwei Hou 2013-10-30 11:17:00 UTC
Description of problem:
After migration, errors like below has been seen several times in development.log of broker, haven't found out why, but attached the log file in case some unknown bugs are missed.

[0;37m2013-10-30 05:46:10.347^[[0m [^[[31mERROR^[[0m] ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/models/pending_app_op_group.rb:130:in `execute'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/models/application.rb:1545:in `run_jobs'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/models/application.rb:1011:in `block in restart'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/models/application.rb:1591:in `run_in_application_lock'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/models/application.rb:1000:in `restart'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/app/controllers/app_events_controller.rb:65: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__2915745775793770126__process_action__859184168362228389__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_431'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-controller-1.16.7/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_431'", "/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__2915745775793770126__process_action__859184168362228389__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


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

How reproducible:
Always(see this 3 times during 3 migration tests)

Steps to Reproduce:
1. Prepare migration data on devenv-stage ami
2. Upgrade devenv-stage to latest as devenv_3966 and migrate


Actual results:
After migration, found many above errors, and this is only reproduced on the migrated instances, a devenv instance doesn't have such error.

Expected results:
Do not have such error

Additional info:

Comment 1 Andy Goldstein 2013-10-30 23:52:27 UTC
Could you please list the exact steps you used to migrate? I tested a scalable PHP + Mongo application and didn't get any errors on my upgrade.

Comment 3 Andy Goldstein 2013-10-31 12:08:30 UTC
Please provide me the exact steps you did:

1) Commands you used to create applications, or at least the cartridges for each app, if the app was scalable, and how many web gears each app had.

2) The ***exact*** commands you used to do the migration

Thanks

Comment 4 Andy Goldstein 2013-10-31 12:58:37 UTC
I see various upgrade errors in the logs:

Most are "Upgrade failed with an unhandled exception: Action upgrade needs a secret_token argument"

A couple are "Unhandled exception performing step: undefined local variable or method `errors' for #<OpenShift::GearUpgradeExtension:0x00000001dc51d0>\
n/usr/libexec/openshift/lib/gear_upgrade_extension.rb:171:in `block (2 levels) in migrate_deployment_system_pre"

Comment 5 Andy Goldstein 2013-10-31 13:08:34 UTC
The node ip-10-244-47-11 didn't get updated packages - its latest RPMs are from 10/22 - that's where the "Upgrade failed with an unhandled exception: Action upgrade needs a secret_token argument" errors came from. These are not errors because the node wasn't upgraded with the new RPMs.

The other error needs more investigation.

Comment 6 Xiaoli Tian 2013-10-31 13:47:57 UTC
(In reply to Andy Goldstein from comment #3)
> Please provide me the exact steps you did:
> 
> 1) Commands you used to create applications, or at least the cartridges for
> each app, if the app was scalable, and how many web gears each app had.
> 
> 2) The ***exact*** commands you used to do the migration
> 
> Thanks

Exact steps for migration:

1) li/misc/maintenance/bin/rhc-populate-sni-proxy

2) oo-admin-broker-cache -c

3) /etc/init.d/rhc-broker restart

4) /etc/init.d/ruby193-mcollective restart

5) /usr/bin/rhc-admin-migrate-datastore --compatible --version 2.0.35

6) /usr/bin/rhc-admin-migrate-datastore --non-compatible --version 2.0.35

7) oo-admin-broker-cache -c

10) /usr/sbin/oo-admin-upgrade upgrade-node --version 2.0.35 --ignore-cartridge-version

Comment 9 Andy Goldstein 2013-10-31 17:51:15 UTC
https://github.com/openshift/li/pull/2073

Comment 10 Jianwei Hou 2013-11-01 11:58:53 UTC
With above fix, the error is gone from development.log. Thanks, mark as verified.