Description of problem: In the rhevm.log on the CFME appliance there are many log entries like: [----] E, [2016-08-10T16:15:09.417939 #13833:1624598] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://mac5254003cbae2.b.b/ovirt-engine/api/ovirt-engine/api/vms/12a6018c-6fa4-4550-9ac3-84b6a6899388/snapshots> Data: If you use wget with the same URL but change it so that /ovirt-engine/api is not repeated: wget --no-check-certificate --user admin@internal --password changeme https://mac5254003cbae2.b.b/ovirt-engine/api/vms/12a6018c-6fa4-4550-9ac3-84b6a6899388/snapshots Then a correct response is returned. Version-Release number of selected component (if applicable): 5.6.0 How reproducible: Only deployed this once. Steps to Reproduce: 1. Deploy RHV 4.0.1.1 2. Deploy CFME 5.6.0 on top of the RHEV deployment. 3. Wait a bit. 4. Check the rhvm.log Actual results: You will get many errors with it trying to talk to the RHV host with the URL's with /ovirt-engine/api duplicated. Expected results: Not to see these log errors. Additional info: This initial deployment of RHV and CFME was done using QCI QCI-1.0-RHEL-7-20160809.t.0
Just providing this comment in case it saves anybody some time. Dug into it a little, found that the Ovirt::Service.resource_get function (from the 'ovirt' gem) is getting called with the path '/ovirt-engine/api/templates/00000000-0000-0000-0000-000000000000/disks', and will produce the url 'https://mac5254003cbae2.b.b/ovirt-engine/api/ovirt-engine/api/templates/00000000-0000-0000-0000-000000000000/disks'. It looks like the Ovirt::Service.api_uri function is supposed to take into account the possibility of a leading '/api/' or '/ovirt-engine/api/', so I'm not sure why it's occurring, but it seems like the error could be happening somewhere around there.
Tested on bare metal with separated hypervisor and engine. To clarify Reproducer step 4: 4A. Ssh to cloudforms VM (hostname and ip address obtainable from Installation Summary and/or Hosts > All Hosts) 4B. Examine /var/www/miq/vmdb/log/rhevm.log Digging into the logfiles: A. Some API request/response pairs are OK: [----] I, [2016-08-11T18:57:33.253287 #13369:64d994] INFO -- : Ovirt::Service#resource_get: Sending URL: <https://<<engine_fqdn>>/ovirt-engine/api> [----] I, [2016-08-11T18:57:33.361251 #13369:64d994] INFO -- : Ovirt::Service#parse_normal_response: Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api> Data length:4471 B. [----] W, [2016-08-11T18:57:37.091690 #13662:826cc0] WARN -- : Ovirt::Event.set_event_name Unknown RHEVM event 843: Host <<hypervisor_fqdn>> has available updates: libvirt. C. Problems can be identified by #parse_error_response: [----] I, [2016-08-11T18:57:47.330227 #13622:f6cca0] INFO -- : Ovirt::Service#resource_get: Sending URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/hosts/8dda8cfe- f904-4e9c-9531-282472bac294/statistics> [----] E, [2016-08-11T18:57:47.449134 #13622:f6cca0] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/host s/8dda8cfe-f904-4e9c-9531-282472bac294/statistics> Data: D. Other instances of problems omitting request part match Fabian's analysis in Comment 3: [----] E, [2016-08-11T18:57:47.456200 #13622:fa6284] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/vms/ 1eee475e-76a8-4a2f-aaef-5d72df14b32d/disks> Data: [----] E, [2016-08-11T18:57:47.456735 #13622:f6d5d8] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/host s/8dda8cfe-f904-4e9c-9531-282472bac294/nics> Data: [----] E, [2016-08-11T18:57:47.457206 #13622:76fdedc] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/vms /1eee475e-76a8-4a2f-aaef-5d72df14b32d/nics> Data: [----] E, [2016-08-11T18:57:47.457631 #13622:76fddc4] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/vms /1eee475e-76a8-4a2f-aaef-5d72df14b32d/snapshots> Data: [----] E, [2016-08-11T18:57:47.458074 #13622:f6d254] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/data centers/00000001-0001-0001-0001-00000000033b/storagedomains> Data: [----] E, [2016-08-11T18:57:47.462369 #13622:fa4164] ERROR -- : Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/api/temp lates/8e9b4e9d-10d8-4173-990f-0fb03ac8be2c/disks> Data: E. This can also be seen in evm.log: [----] E, [2016-08-11T18:57:47.449081 #13622:f6cca0] ERROR -- : <RHEVM> Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/ api/hosts/8dda8cfe-f904-4e9c-9531-282472bac294/statistics> Data: F. Another related error: [----] I, [2016-08-11T19:14:29.123609 #13359:64d994] INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager#with_provider_connection) Connecting through ManageIQ::Providers::Redhat::InfraManager: [b z_1366384-RHEV] [----] I, [2016-08-11T19:14:29.199245 #13359:64d994] INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager#connect) Using stored API path '/ovirt-engine/api'. [----] E, [2016-08-11T19:14:29.305973 #13359:64d994] ERROR -- : <RHEVM> Ovirt::Service#parse_error_response Return from URL: <https://<<engine_fqdn>>/ovirt-engine/api/ovirt-engine/ api/users/0000002c-002c-002c-002c-000000000323> Data: [----] E, [2016-08-11T19:14:29.306484 #13359:64d994] ERROR -- : MIQ(MiqQueue#deliver) Message id: [1000000000216], Error: [Ovirt::MissingResourceError] [----] E, [2016-08-11T19:14:29.306564 #13359:64d994] ERROR -- : [Ovirt::MissingResourceError]: Ovirt::MissingResourceError Method:[rescue in deliver] [----] E, [2016-08-11T19:14:29.306612 #13359:64d994] ERROR -- : /opt/rh/cfme-gemset/gems/ovirt-0.10.0/lib/ovirt/service.rb:302:in `parse_error_response' /opt/rh/cfme-gemset/gems/ovirt-0.10.0/lib/ovirt/service.rb:273:in `block in resource_verb' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `call' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `process_result' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:504:in `block in transmit' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:853:in `start' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:494:in `transmit' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:202:in `execute' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:52:in `execute' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/resource.rb:51:in `get' /opt/rh/cfme-gemset/gems/ovirt-0.10.0/lib/ovirt/service.rb:268:in `resource_verb' /opt/rh/cfme-gemset/gems/ovirt-0.10.0/lib/ovirt/service.rb:242:in `resource_get' /opt/rh/cfme-gemset/gems/ovirt-0.10.0/lib/ovirt/base.rb:231:in `find_by_href' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/event_parser.rb:38:in `block in event_to_hash' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager.rb:103:in `with_provider_connection' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/event_parser.rb:37:in `event_to_hash' /var/www/miq/vmdb/app/models/ems_event.rb:68:in `add_rhevm' /var/www/miq/vmdb/app/models/miq_queue.rb:343:in `block in deliver' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:89:in `block in timeout' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `block in catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:104:in `timeout' /var/www/miq/vmdb/app/models/miq_queue.rb:341:in `deliver' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:106: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:334:in `block in do_work_loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:331: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:128: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:346:in `block in start' /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:344:in `start' /var/www/miq/vmdb/app/models/miq_worker.rb:274: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:52: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:173:in `start' /var/www/miq/vmdb/app/models/miq_server.rb:265:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:92:in `start' /var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>' [----] I, [2016-08-11T19:14:29.306699 #13359:64d994] INFO -- : MIQ(MiqQueue#delivered) Message id: [1000000000216], State: [error], Delivered in [0.184026787] seconds ...
*** This bug has been marked as a duplicate of bug 1353323 ***