Bug 1445995

Shveta,

Can you upload the evm.log?

thanks,
James

Created attachment 1274759 [details]
evm log

Created attachment 1274760 [details]
evm1.log

Added another repo(repo_1) with same url .

Appliance - https://10.8.198.122
Note : To refresh On Ansible - Repository page - I selected the checkbox for the repo and Configuration - refresh.(from the all repo page )


I think the repository gets refreshed when you click on the repo(not checkbox) and then refresh (from the individual repo page )

James, is this just a problem that the UI is calling a full refresh and not calling the targeted refresh from the repo list page?

The log shows there are 2 create_in_provider of repos.

1) failed because Tower complained that there's already an existing one with the same name 'test_repo'

[----] I, [2017-04-27T13:11:31.438598 #2948:d6d134]  INFO -- : MIQ(MiqPriorityWorker::Runner#get_message_via_drb) Message id: [17737], MiqWorker id: [47], Zone: [default], Role: [ems_operations], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource.
create_in_provider], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [2, {:name=>"test_repo", :description=>"", :scm_type=>"git", :scm_url=>"https://github.com/sshveta/Ansible_Playbooks", :authentication_id=>nil, :scm_branch=>"", :scm_clean=>false, :scm_delete_on_update=>false, :scm_update_on_launch=>true}], Dequeued in: [4.6264
55743] seconds
[----] E, [2017-04-27T13:11:31.566194 #2948:d6d134] ERROR -- : AnsibleTowerClient::Middleware::RaiseTowerError Response Body:
{"name"=>["Project with this Name already exists."]}


2) 2nd one succeeded with repo name = 'repo_1'. 

[----] I, [2017-04-27T13:16:02.058644 #2956:d6d134]  INFO -- : MIQ(MiqPriorityWorker::Runner#get_message_via_drb) Message id: [17777], MiqWorker id: [48], Zone: [default], Role: [ems_operations], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource.create_in_provider], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [2, {:name=>"repo_1", :description=>"", :scm_type=>"git", :scm_url=>"https://github.com/sshveta/Ansible_Playbooks/blob/master/vmware/Install_Apache.yml", :authentication_id=>nil, :scm_branch=>"", :scm_clean=>false, :scm_delete_on_update=>false, :scm_update_on_launch=>true}], Dequeued in: [3.6370567] seconds


I couldn't find logs related to the repo name='sshveta_repo' as shown in your screen shot.


With the story https://www.pivotaltracker.com/story/show/143133279 now done (UI PR missed last built and will be there in tomorrow's appliance build), you'll be able to see if a repo failed to sync (Tower side). I.e. if the url is a wrong one, (or due to other factors) and Tower fails to get the list of playbooks (into Tower's own db), MIQ UI would show you the status.

What we need to do is to activate the target refresh on the repo being created/updated and so that playbooks will be loaded right away.

James, won't this be done by events?  For example, as soon as MIQ creates the repo in Ansible, Ansible should emit an event caught by MIQ, which should trigger the targeted refresh.

Also, you might be able to kick off a targeted refresh when updating a repo, but I'm not sure you will be able to do a targeted refresh when creating a repo.  There's no object to target.  And, the only work around I've seen in this case involves a targeted refresh based on an event.

For that, you'd probably have to rope in Adam to get some pointers.

Yes,

I am working on a PR to invoke targeted refresh when updating/deleting the repo. Right, for creation, I can't (efficiently).

Not sure if event is triggering targeted refresh. That'd be ideal and handle all cases. Let me check. Thanks for the lead.

Another appliance : https://10.8.198.207 .



EVM log 
==============================

m_clean=>false, :scm_delete_on_update=>false, :scm_update_on_launch=>true, :href=>"https://10.8.198.207/api/configuration_script_sources/1", :id=>1, :manager_id=>2, :manager_ref=>"6", :created_at=>"2017-05-01T18:29:58Z", :updated_at=>"2017-05-01T18:29:58Z", :type=>"ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource", :status=>"failed", :actions=>[{:name=>"edit", :method=>"post", :href=>"https://10.8.198.207/api/configuration_script_sources/1"}, {:name=>"delete", :method=>"post", :href=>"https://10.8.198.207/api/configuration_script_sources/1"}, {:name=>"delete", :method=>"delete", 
:href=>"https://10.8.198.207/api/configuration_script_sources/1"}], :task_id=>14}], Dequeued in: [1.205810535] seconds
[----] I, [2017-05-01T14:34:13.968467 #2868:781130]  INFO -- : MIQ(MiqQueue#deliver) Message id: [3621], Delivering...
[----] I, [2017-05-01T14:34:13.978873 #2868:781130]  INFO -- : MIQ(ManageIQ::Providers::EmbeddedAnsible::Provider#with_provider_connection) Connecting through ManageIQ::Providers::EmbeddedAnsible::Provider: [Embedded Ansible]
[----] E, [2017-05-01T14:34:14.331913 #2868:781130] ERROR -- : MIQ(MiqQueue#deliver) Message id: [3621], Error: [undefined method `href=' for #<AnsibleTowerClient::Project:0x000000154e9458>]
[----] E, [2017-05-01T14:34:14.332536 #2868:781130] ERROR -- : [NoMethodError]: undefined method `href=' for #<AnsibleTowerClient::Project:0x000000154e9458>  Method:[rescue in deliver]
[----] E, [2017-05-01T14:34:14.332619 #2868:781130] ERROR -- : /opt/rh/cfme-gemset/gems/ansible_tower_client-0.12.1/lib/ansible_tower_client/base_model.rb:88:in `block in update_attributes!'


/opt/rh/cfme-gemset/gems/ansible_tower_client-0.12.1/lib/ansible_tower_client/base_model.rb:84:in `each'
/opt/rh/cfme-gemset/gems/ansible_tower_client-0.12.1/lib/ansible_tower_client/base_model.rb:84:in `update_attributes!'
/var/www/miq/vmdb/app/models/manageiq/providers/ansible_tower/shared/automation_manager/tower_api.rb:67:in `block in update_in_provider'
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:15:in `block in with_provider_object'
/var/www/miq/vmdb/app/models/provider.rb:49:in `with_provider_connection'
/var/www/miq/vmdb/app/models/manageiq/providers/ansible_tower/shared/automation_manager.rb:5:in `with_provider_connection'
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:12:in `with_provider_object'
/var/www/miq/vmdb/app/models/manageiq/providers/ansible_tower/shared/automation_manager/tower_api.rb:66:in `update_in_provider'
/var/www/miq/vmdb/app/models/miq_queue.rb:347:in `block in deliver'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:91:in `block in timeout'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `block in catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:106:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:107:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:135:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:153:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:336:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:333:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:333:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:155:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:130:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:21:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:339:in `block in start_runner'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:337:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:348:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:266:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:150: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:160:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:251:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:91:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2017-05-01T14:34:14.333298 #2868:781130]  INFO -- : MIQ(MiqQueue#delivered) Message id: [3621], State: [error], Delivered in [0.364837067] seconds
[----] I, [2017-05-01T14:34:14.335114 #2868:781130]  INFO -- : MIQ(MiqQueue#m_callback) Message id: [3621], Invoking Callback with args: ["Finished", "error", "undefined method `href=' for #<AnsibleTowerClient::Project:0x000000154e9458>", "nil"]
[----] I, [2017-05-01T14:34:14.335453 #2868:781130]  INFO -- : MIQ(MiqTask#update_status) Task: [14] [Finished] [Error] [undefined method `href=' for #<AnsibleTowerClient::Project:0x000000154e9458>]
[----] I, [2017-05-01T14:34:17.463965 #2878:781130]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 5.
[----] I, [2017-05-01T14:34:17.469713 #2878:781130]  INFO -- : MIQ(MiqQueue.put) Message id: [3622],  id: [], Zone: [default], Role: [], Server: [cbbfd368-2a0c-11e7-a8b6-001a4a4475a7], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []

Created attachment 1275463 [details]
evm log

:type=>"ManageIQ::Providers::EmbeddedAnsible::AutomationManager::ConfigurationScriptSource", :status=>"failed", :actions=>[{:name=>"edit", :method=>"post", :href=>"https://10.8.198.207/api/configuration_script_sources/1"}, {:name=>"delete", :method=>"post", :href=>"https://10.8.198.207/api/configuration_script_sources/1"}, {:name=>"delete", :method=>"delete", 
:href=>"https://10.8.198.207/api/configuration_script_sources/1"}], :task_id=>14}

UI is sending in extra stuff that fails Ansible Tower Ruby Client again.

Hi , Please Note that If I click on the repo and refresh it from the individual repo page , I too see the playbooks .

The error is when I refresh the repo from the all repo page(add new repo page) , means - click on the checkbox for the repo and refresh , It doesn't refresh.

Laura, Shevta the discrepancy between details view and list view was fixed in https://github.com/ManageIQ/manageiq-ui-classic/pull/1176

*** Bug 1447292 has been marked as a duplicate of this bug. ***

Assign back to James to add a refresh after a provider edit.

PR for the extra attributes sent by the UI for repository edit: https://github.com/ManageIQ/manageiq-ui-classic/pull/1230

https://github.com/ManageIQ/manageiq/pull/14954

A second PR is merged https://github.com/ManageIQ/manageiq/pull/15025


Now we are done.

*** Bug 1444381 has been marked as a duplicate of this bug. ***

Verified in 5.9.0.2.20171010190026_0413a06. Playbooks are loaded after repository's editing.