Bug 1539782 - Unable to add playbook repos after webui update
Summary: Unable to add playbook repos after webui update
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Appliance
Version: 5.9.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: GA
: 5.10.0
Assignee: Nick Carboni
QA Contact: luke couzens
URL:
Whiteboard: ansible_embed:black:upgrade
Depends On:
Blocks: 1552783
TreeView+ depends on / blocked
 
Reported: 2018-01-29 15:34 UTC by luke couzens
Modified: 2019-02-11 13:58 UTC (History)
6 users (show)

Fixed In Version: 5.10.0.0
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1552783 (view as bug list)
Environment:
Last Closed: 2019-02-11 13:58:50 UTC
Category: ---
Cloudforms Team: CFME Core
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description luke couzens 2018-01-29 15:34:29 UTC
Description of problem:Unable to add playbook repos after webui update


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


How reproducible:100%


Steps to Reproduce:
1.Provision 5.9.0.17
2.enable embedded ansible
3.add latest 5.9 repos
4.add rhsm subscription
5.check for updates
6.run update through ui
7.add new repo

Actual results:
events show embedded ansible is active and new repo's are completed successfully but they don't appear in the repositories list.


Expected results:
repos shown in list after adding succefully


Additional info:
It seems the ansible provider works did not start correctly after the update.

Work around is to run provider.authentication_check which will kick the workers back into life.

Comment 2 Gregg Tanzillo 2018-01-30 14:48:52 UTC
Luke, can you verify whether the embedded ansible worker was actually started when you attempted to add the new repo? It's not clear from the info if the worker only got started when you did the authentication_check.

Comment 3 luke couzens 2018-01-30 15:15:02 UTC
Hey Greg, 

so Nick and I were looking at my appliance yesterday. The worker was enabled in the ui and the services were running e.i supervisord, nginx and rabbitmq-server

irb(main):013:0> EmbeddedAnsible.new.alive?
=> true

though the workers were up we saw this:

irb(main):011:0> provider.authentications.first.status_details => "<!DOCTYPE HTML PUBLIC \"-//IETF//DTD HTML 2.0//EN\">\n<html><head>\n<title>503 Service Unavailable</title>\n</head><body>\n<h1>Service Unavailable</h1>\n<p>The server is temporarily unable to service your..."

irb(main):004:0> provider = ManageIQ::Providers::EmbeddedAnsible::Provider.first
PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 1, in use: 1, waiting_in_queue: 0
=> #<ManageIQ::Providers::EmbeddedAnsible::Provider id: 1, type: "ManageIQ::Providers::EmbeddedAnsible::Provider", name: "Embedded Ansible", guid: nil, zone_id: 1, created_at: "2018-01-29 14:32:57", updated_at: "2018-01-29 14:32:57", tenant_id: 1>
irb(main):005:0> provider.authentication_status
=> "Error"

Comment 4 Nick Carboni 2018-02-12 14:43:37 UTC
My plan for this is to re-validate the credentials if we can access the provider using the API, but the credentials are not valid.

In a "normal" provider the user would be able to see that the credentials are not valid and take action to fix it. That's not the case here, so we have to do it for them.

Comment 6 CFME Bot 2018-02-12 21:51:42 UTC
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/6e57b51049cfe92c4d27ef771572f1ec2e434a9f

commit 6e57b51049cfe92c4d27ef771572f1ec2e434a9f
Author:     Nick Carboni <ncarboni>
AuthorDate: Mon Feb 12 13:48:52 2018 -0500
Commit:     Nick Carboni <ncarboni>
CommitDate: Mon Feb 12 13:48:52 2018 -0500

    Re-check the provider authentication if the API is responding
    
    This fixes an issue where we hit a race condition when
    the ansible API is not ready yet, but is technically "alive".
    
    Before we would see that it was alive, but would never re-check
    the credentials so we would never get refresh workers.
    
    Fixes https://bugzilla.redhat.com/show_bug.cgi?id=1539782

 app/models/embedded_ansible_worker/runner.rb       |  6 +++-
 spec/models/embedded_ansible_worker/runner_spec.rb | 35 ++++++++++++++++++++++
 2 files changed, 40 insertions(+), 1 deletion(-)

Comment 8 luke couzens 2018-06-21 10:09:30 UTC
I am seeing some issues here, after the webui update adding a new repo fails. I see the following in evm.log

[----] I, [2018-06-21T05:48:08.263818 #35572:7d0f8c]  INFO -- : MIQ(MiqTask#update_status) Task: [14] [Active] [Ok] [Task starting]
[----] I, [2018-06-21T05:48:08.274971 #35572:7d0f8c]  INFO -- : MIQ(ManageIQ::Providers::EmbeddedAnsible::Provider#with_provider_connection) Connecting through ManageIQ::Providers::EmbeddedAnsible::Provider: [Embedded Ansible]
[----] E, [2018-06-21T05:48:08.327113 #35572:7d0f8c] ERROR -- : AnsibleTowerClient::Middleware::RaiseTowerError Response Body:
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>503 Service Unavailable</title>
</head><body>
<h1>Service Unavailable</h1>
<p>The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.</p>
</body></html>

[----] I, [2018-06-21T05:48:08.327679 #35572:7d0f8c]  INFO -- : MIQ(ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource.notify) ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource in_provider creation with parameters: name=lcouzens failed
[----] E, [2018-06-21T05:48:08.353281 #35572:7d0f8c] ERROR -- : MIQ(MiqQueue#deliver) Message id: [440], Error: [<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>503 Service Unavailable</title>
</head><body>
<h1>Service Unavailable</h1>
<p>The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.</p>
</body></html>
]
[----] E, [2018-06-21T05:48:08.353534 #35572:7d0f8c] ERROR -- : [AnsibleTowerClient::ClientError]: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>503 Service Unavailable</title>
</head><body>
<h1>Service Unavailable</h1>
<p>The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.</p>
</body></html>
  Method:[block in method_missing]
[----] E, [2018-06-21T05:48:08.353628 #35572:7d0f8c] ERROR -- : /opt/rh/cfme-gemset/gems/ansible_tower_client-0.15.0/lib/ansible_tower_client/middleware/raise_tower_error.rb:21:in `on_complete'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/response.rb:9:in `block in call'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/response.rb:57:in `on_complete'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/response.rb:8:in `call'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/request/url_encoded.rb:15:in `call'
/opt/rh/cfme-gemset/gems/faraday_middleware-0.10.1/lib/faraday_middleware/response/follow_redirects.rb:76:in `perform_with_redirection'
/opt/rh/cfme-gemset/gems/faraday_middleware-0.10.1/lib/faraday_middleware/response/follow_redirects.rb:64:in `call'
/opt/rh/cfme-gemset/gems/faraday_middleware-0.10.1/lib/faraday_middleware/request/encode_json.rb:23:in `call'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:139:in `build_response'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/connection.rb:377:in `run_request'
/opt/rh/cfme-gemset/gems/faraday-0.9.2/lib/faraday/connection.rb:177:in `post'
/opt/rh/cfme-gemset/gems/ansible_tower_client-0.15.0/lib/ansible_tower_client/api.rb:116:in `method_missing'
/opt/rh/cfme-gemset/gems/ansible_tower_client-0.15.0/lib/ansible_tower_client/base_model.rb:57:in `create!'
/opt/rh/cfme-gemset/gems/ansible_tower_client-0.15.0/lib/ansible_tower_client/collection.rb:35:in `create!'
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ansible_tower-421e2eed400a/app/models/manageiq/providers/ansible_tower/shared/automation_manager/tower_api.rb:8:in `raw_create_in_provider'
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ansible_tower-421e2eed400a/app/models/manageiq/providers/ansible_tower/shared/automation_manager/tower_api.rb:13:in `create_in_provider'
/var/www/miq/vmdb/app/models/miq_queue.rb:451:in `block in dispatch_method'
/usr/share/ruby/timeout.rb:93:in `block in timeout'
/usr/share/ruby/timeout.rb:33:in `block in catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:108:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:449:in `dispatch_method'
/var/www/miq/vmdb/app/models/miq_queue.rb:426:in `block in deliver'
/var/www/miq/vmdb/app/models/user.rb:266:in `with_user_group'
/var/www/miq/vmdb/app/models/miq_queue.rb:426:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:104:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:134:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:152:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:329:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:127:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:22:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:402:in `block in start_runner_via_fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:400:in `start_runner_via_fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:390:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:441:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:271:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:147:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:239:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:27:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:48:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2018-06-21T05:48:08.353763 #35572:7d0f8c]  INFO -- : MIQ(MiqQueue#delivered) Message id: [440], State: [error], Delivered in [0.115253606] seconds
[----] I, [2018-06-21T05:48:08.355813 #35572:7d0f8c]  INFO -- : MIQ(MiqQueue#m_callback) Message id: [440], Invoking Callback with args: ["Finished", "error", "<!DOCTYPE HTML PUBLIC \"-//IETF//DTD HTML 2.0//EN\">\n<html><head>\n<title>503 Service Unavailable</title>\n</head><body>\n<h1>Service Unavailable</h1>\n<p>The server is temporarily unable to service your\nrequest due to maintenance downtime or capacity\nproblems. Please try again later.</p>\n</body></html>\n", "nil"]
[----] I, [2018-06-21T05:48:08.356004 #35572:7d0f8c]  INFO -- : MIQ(MiqTask#update_status) Task: [14] [Finished] [Error] [<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>503 Service Unavailable</title>
</head><body>
<h1>Service Unavailable</h1>
<p>The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.</p>
</body></html>

Also it seems that supervisord, nginx and rabbitmq-server get stopped.

A work around is to reboot the appliance, that seems bring everything back up correctly and allow you to add repos again.

Comment 9 Nick Carboni 2018-06-21 21:13:26 UTC
Luke,

How did you test this on 5.10? As this is the first release what did you update to in the web UI?

Or was this an upgrade from 5.9 to 5.10 where this happened?

Comment 10 luke couzens 2018-06-22 08:12:33 UTC
Hey Nick,

I tested 5.10.0.0 to 5.10.0.1

Comment 11 Nick Carboni 2018-06-26 18:50:44 UTC
The upgrade doesn't seem to work at all for me. In my test I followed the following steps:

- Add new repos to /etc/yum.repos.d/cfme.repo
- Add credentials to web-ui
- Check for updates
- Apply updates

Observed:

Update process attempts to stop evmserverd service but systemd sees an error and attempts to restart it:

Jun 26 14:37:48 localhost.localdomain systemd[1]: evmserverd.service: main process exited, code=killed, status=6/ABRT
Jun 26 14:37:56 localhost.localdomain sh[24104]: Stopping EVM gracefully...
Jun 26 14:37:56 localhost.localdomain systemd[1]: Unit evmserverd.service entered failed state.
Jun 26 14:37:56 localhost.localdomain systemd[1]: evmserverd.service failed.
Jun 26 14:37:56 localhost.localdomain systemd[1]: evmserverd.service holdoff time over, scheduling restart.
Jun 26 14:37:56 localhost.localdomain systemd[1]: Starting EVM server daemon...
Jun 26 14:38:05 localhost.localdomain sh[24127]: Starting EVM...
Jun 26 14:38:05 localhost.localdomain sh[24127]: Running EVM in background...
Jun 26 14:38:05 localhost.localdomain systemd[1]: Started EVM server daemon.

Now both `yum update -y cfme-appliance` and evmserverd are running simultaneously. When `yum update` completes, the server UI is unusable.

After `systemctl restart evmserverd` is run the update seems to be successful.

This is also the case when running the update manually through the command line:

- systemctl stop evmserverd
- yum update -y cfme-appliance
- systemctl start evmserverd

This case looks like it doesn't really have anything to do with embedded ansible and should be a separate issue. Are you seeing the update complete successfully and then failures with embedded ansible after? Do you have an appliance where this was reproduced?


Note You need to log in before you can comment on or make changes to this bug.